Output of times in download.log

Output of times in download.log

Postby Dalai » 24.03.2019, 23:57

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
Dalai
 
Posts: 1041
Joined: 12.07.2016, 21:00

Re: Output of times in download.log

Postby aker » 25.03.2019, 10:22

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")
Wer Rechtschreibfehler findet, darf sie behalten oder an den Meistbietenden versteigern. / Everybody finding a misspelling is allowed to keep or sell it.
aker

WSUS Offline Update „Community Edition“
https://gitlab.com/wsusoffline/wsusoffline/-/releases
aker
 
Posts: 3999
Joined: 02.03.2011, 15:32

Re: Output of times in download.log

Postby Dalai » 25.03.2019, 16:28

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
Dalai
 
Posts: 1041
Joined: 12.07.2016, 21:00

Re: Output of times in download.log

Postby WSUSUpdateAdmin » 26.03.2019, 15:49

Hi.

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

Cheers,
Torsten
WSUSUpdateAdmin
Administrator
 
Posts: 2245
Joined: 07.07.2009, 14:38

Re: Output of times in download.log

Postby Dalai » 31.03.2019, 20:56

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
Dalai
 
Posts: 1041
Joined: 12.07.2016, 21:00

Re: Output of times in download.log

Postby WSUSUpdateAdmin » 01.04.2019, 15:47

Hi.

Fixed.
Thanks a lot! :)

Regards,
Torsten
WSUSUpdateAdmin
Administrator
 
Posts: 2245
Joined: 07.07.2009, 14:38


Return to Anregungen / Suggestions

Who is online

Users browsing this forum: No registered users and 7 guests