Page 1 of 1

Output of times in download.log

PostPosted: 24.03.2019, 23:57
by Dalai
Hi there. :)

Unfortunately I have to report another bug in DownloadUpdates.cmd :|, one that's a little bit annoying because it limits the usefulness of the download.log. This bug is present ever since the output of the download process was extended to include all URLs and file names; don't recall which version and I haven't been able to find the relevant change in the history so far.

Anyway. Currently, the call to the downloader (wget, aria2) is done in a nested for-loop. This is alright, but it creates a problem. Let me illustrate the issue with this short example batch:
Code: Select all
for /L %%i IN (1,1,10) DO (
    echo %RANDOM%
    echo %time%
    timeout /T 1
)
What do you see when running it? Something like this:
Code: Select all
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
28383
23:19:17,48

Gewartet wird 0 Sekunden. Weiter mit beliebiger Taste...
23:19:27,15
Neither is the number random as it should be nor is the time correct when the difference between the lines should be around 1 second. Why is this? Because environment variables are set when the (last) bracketed block is left - but not before or within. In this case there's only one bracketed block, which is the loop. This limitation also applies to the pre-defined variables like %date%, %time%, %random% and so on.

There are at least two solutions to tackle this problem.
  • Use delayed expansion, like this (ugly):
    Code: Select all
    setlocal EnableDelayedExpansion
    for /L %%i IN (1,1,10) DO (
        echo !RANDOM!
        echo !time!
        timeout /T 1
    )
    endlocal
  • Call a label to output the variable contents, like this (not nice either):
    Code: Select all
    for /L %%i IN (1,1,10) DO (
        call :SECT
        timeout /T 1
    )

    :SECT
    echo %time%
    goto :EOF
Maybe there's another way to get the date and time, like via WMI or something.

Regards
Dalai

Re: Output of times in download.log

PostPosted: 25.03.2019, 10:22
by aker
I'd use VBS instead of WMI.

I'm not that god in VBS, but if I correctly translate from VB.NET toVBS it should look similar to this
Code: Select all
Format(Now(), "yyyy-MM-dd hh:mm:ss")

Re: Output of times in download.log

PostPosted: 25.03.2019, 16:28
by Dalai
I just got an idea. One could use a new label like :LOG and pass everything to be logged to it except the date and time. Like this:
Code: Select all
        %DLDR_PATH% %DLDR_COPT% %DLDR_POPT% ..\client\%1\%2 %%l
        if errorlevel 1 (
          echo Warning: Download of %%l failed.
          call :LOG "Warning: Download of %%l failed"
        ) else (
          call :LOG "Info: Downloaded/validated %%l to ..\client\%1\%2"
        )
....
call :LOG "Info: Downloaded/validated %LINES_COUNT% dynamically determined updates for %1 %2"
...
REM and so on

:LOG
if "%~1"=="" goto :EOF
echo %DATE% %TIME% - %~1 >>%DOWNLOAD_LOGFILE%
goto :EOF
Similar to using/calling a function in a proper programming language ;). This would also remove the "hundreds" of uses of ">>%DOWNLOAD_LOGFILE%" in DownloadUpdates.cmd. It's probably slower than it is now, but definitely better than calling another external program (like WMI or VBS).

Regards
Dalai

Re: Output of times in download.log

PostPosted: 26.03.2019, 15:49
by WSUSUpdateAdmin
Hi.

Good point, good idea! :)
Just a moment, please... ;)

Cheers,
Torsten

Re: Output of times in download.log

PostPosted: 31.03.2019, 20:56
by Dalai
WSUSUpdateAdmin wrote:Just a moment, please... ;)

*thumbs up* (the corresponding smilie is still missing in this forum ;)).

Two small issues with the change though:
  • There's at least one occurence of
    Code: Select all
    call :Log ... >>%DOWNLOAD_LOGFILE%
    in DownloadUpdates.cmd, i.e. the redirection to the log shouldn't be there. Guess that would've happened eventually when making such a fundamental change...
  • Writing something like
    Code: Select all
    call :Log "Info ...^(foo bar^)"
    makes the circumflex part of the logged text, i.e. not only the brackets will be logged but also the circumflexes. It's required to escape the brackets in a normal echo statement/command, and in loops, but IIRC the circumflex is part of the regular output when quoted.

Regards
Dalai

Re: Output of times in download.log

PostPosted: 01.04.2019, 15:47
by WSUSUpdateAdmin
Hi.

Fixed.
Thanks a lot! :)

Regards,
Torsten