0

We have a conversion process that is calling many Windows batch script files and writing the output and errors to a single output file. At times, there is a lock on the output file that causes the script to terminate. Consequently, the batch file terminates and raises an error code. Is there a way to ignore the error if the output file is locked? For example, if the ScriptOutput file in the example below is locked, is is it possible to ignore the error with redirecting the output and continue execution of the script?

@echo( >> D:\Conversion\log\ScriptOutput.log 2>>&1

D:\Conversion\log\ScriptOutput.log 2>>&1

@echo %date% %time% BEGIN OUTPUT FOR MoveTransDataToReporting.dtsx Script >> D:\Conversion\log\ScriptOutput.log 2>>&1
@echo(  >> D:\Conversion\log\ScriptOutput.log 2>>&1

"C:\Program Files (x86)\Microsoft SQL Server\120\DTS\Binn\DTExec.exe" /FILE "\"D:\Conversion\sql\MoveTransDataToReporting3Years.dtsx\"" /CHECKPOINTING OFF  /REPORTING EWCDI >> D:\Conversion\log\ScriptOutput.log 2>&1

@echo(  >> D:\Conversion\log\ScriptOutput.log 2>>&1
@echo %date% %time% END OUTPUT FOR MoveTransDataToReporting.dtsx Script >> D:\Conversion\log\ScriptOutput.log 2>>&1
@echo ************************************************************************************************************************************** >> D:\Conversion\log\ScriptOutput.log 2>>&1
Squashman
  • 13,649
  • 5
  • 27
  • 36
Grasshopper
  • 4,717
  • 9
  • 36
  • 62
  • 1
    Put all `echo` commands that write to the output file in between `(`/`)` and redirect the whole block by `>> D:\Conversion\log\ScriptOutput.log 2>>&1`; put another `(`/`)` around the whole thing including the redirection; append something like `&& (action upon success) || (action upon failure)`... – aschipfl Jun 17 '18 at 08:02

2 Answers2

1

I suggest following batch file to solve this problem:

@echo off
for /F "tokens=2,3 delims==.+-" %%I in ('%SystemRoot%\System32\wbem\wmic.exe OS GET LocalDateTime /VALUE') do set "LogFileName=%TEMP%\%~n0_%%I%%J.log"

>>"%LogFileName%" echo/
>>"%LogFileName%" echo %date% %time% BEGIN OUTPUT FOR MoveTransDataToReporting.dtsx Script
>>"%LogFileName%" echo/

"C:\Program Files (x86)\Microsoft SQL Server\120\DTS\Binn\DTExec.exe" /FILE "D:\Conversion\sql\MoveTransDataToReporting3Years.dtsx" /CHECKPOINTING OFF /REPORTING EWCDI >>"%LogFileName%" 2>&1

>>"%LogFileName%" echo/
>>"%LogFileName%" echo %date% %time% END OUTPUT FOR MoveTransDataToReporting.dtsx Script
>>"%LogFileName%" echo **************************************************************************************************************************************

set "RetryCount=0"

:MergeLogs
for %%I in ("%TEMP%\%~n0_????????????????????.log") do (
    ( type "%%I" >>"D:\Conversion\log\ScriptOutput.log" ) 2>nul && (
        del "%%I" & if "%%I" == "%LogFileName%" goto :EOF
    ) || goto NextRetry
)
goto :EOF

:NextRetry
set /A RetryCount+=1
if %RetryCount% == 30 goto :EOF
echo Retry %RetryCount% to merge the logs.
if exist %SystemRoot%\System32\timeout.exe (
    %SystemRoot%\System32\timeout.exe /T 1 /NOBREAK >nul
) else (
    %SystemRoot%\System32\ping.exe -n 2 127.0.0.1 >nul
)
goto MergeLogs

The first FOR loop executes the following command line in a separate command process started by FOR in background:

C:\System32\wbem\wmic.exe OS GET LocalDateTime /VALUE

From the line with data output by this command line is taken the current date and time with current microsecond (in real only current millisecond) in format yyyyMMddHHmmss.microsecond. For a detailed explanation see the answer on: Why does %date% produce a different result in batch file executed as scheduled task? The current date and time in format yyyyMMddHHmms are assigned to loop variable I and the current microsecond to loop variable J.

This date/time string is concatenated with folder path represented by %TEMP% and name of batch file represented by %~n0 with an additional underscore to a full qualified log file name with extension .log.

So a log file is created in folder for temporary files on every start of the batch file MoveData.bat with a name like MoveData_20180617105952343000.log, except the batch file is started twice in same millisecond which hopefully never occurs.

The ECHO command lines are redirected without trailing spaces into the temporary log file as long as the ECHO command lines in batch file have no trailing spaces/tabs. The ECHO command lines in batch code in question write the messages with the space before redirection operator >> as trailing space into the log file.

On the command line with DTExec.exe both \" are removed because I think they are not necessary here. Also on Windows command line it is not possible to define an argument string enclosed in double quotes which contains " itself as literal character of the argument string. " cannot be escaped on Windows command line neither with \ nor with ^ which is interpreted as escape character by Windows command processor.

The creation of the log file with current date/time including the current millisecond in folder for temporary files should never fail.

Next the temporary log file should be appended to log file documenting all conversions. This can fail for example if the log file is opened in an application for viewing its content and the application opened the file with a write lock.

For that reason a FOR loop is used to append every log file matching the specified wildcard pattern in folder for temporary files to the summary log file.

The main advantage of date/time format yyyyMMddHHmmssµs is that file names containing the date/time in this format sorted alphabetically are at the same time also sorted by date with oldest first and newest last. The folder for temporary files is by default on an NTFS partition. The new technology file system returns a list of file names matching a wildcard pattern always sorted alphabetically. Therefore the FOR loop processes the existing temporary log files of this batch file from oldest to newest.

The FOR loop gets the file name of a temporary log file with full path created by this batch file and executes the command line type "%%I" >>"D:\Conversion\log\ScriptOutput.log" to append the contents of this log file to summary log file. The command line is enclosed in a command block with ( and ) to verify if that was successful or failed.

The temporary log file is deleted on success appending the temporary log file to summary log file. And if the successfully appended log file is the same log file as this batch file just created before, the batch file execution is exited. Otherwise the appended log file was an older one which could not be appended to summary log file on former execution of the batch file and so the next temporary log file is processed by FOR.

But if appending the temporary log file to summary log file failed because of summary log file is currently write-protected for whatever reason, the FOR loop is exited with a jump to label NextRetry.

There is incremented a retry counter and if the batch file has not already tried 30 times to append a temporary log file to summary log file, it waits one second using either TIMEOUT (Windows 7 or Windows Server 2008 or any later Window version) or PING (older Windows versions) and then makes one more attempt to append the oldest existing temporary log file to summary log file.

The advantages of this method for log file management:

  • Every batch file execution is always logged even if the summary log file is write-protected during execution of the batch file.
  • A temporary created log file which could not be appended to summary log file although 30 attempts have been made because of summary log file is opened in an application to view its contents for several minutes is appended later by the batch file on any later execution on which summary log file is not write-protected anymore.
  • Previously created temporary log files are appended in correct chronological order to summary log file thanks to date/time format yyyyMMddHHmmssµs and NTFS returning the list of file names matching a pattern sorted alphabetically which means in this case from oldest to newest file.
  • The batch file appends only temporary log files from older executions and the temporary log file created by the current execution to the summary log file. So if the batch file is executed once more while already running and therefore one more, newer temporary log file is created already which does not yet contain all information because of DTExec.exe is currently running, this newer temporary log file is ignored by the execution instance of the batch file which was started first.

It might be easier to understand the log file management by do following:

  1. Put ECHO left to the command line starting DTExec.exe and save the batch file.
  2. Open a command prompt window and run the batch file once from within the command prompt window to create D:\Conversion\log\ScriptOutput.log.
  3. Execute the command attrib +r D:\Conversion\log\ScriptOutput.log to write-protect the summary log file to simulate an application opening the file with a write lock.
  4. Run the batch file from command prompt window once again. It can be seen that it fails 30 times to append the temporary log file on waiting more than 30 seconds.
  5. Open a second command prompt window and prepare the execution of the command
    attrib -r D:\Conversion\log\ScriptOutput.log by just typing this command line.
  6. Switch to first command prompt window and run the batch file a third time. While the retries are executed with pausing 1 second between each attempt, switch to second command prompt window and execute the already prepared ATTRIB command line to remove the read-only attribute from summary log file.
  7. Switch back to first command prompt window and it can be seen that the retry loop exited.
  8. Remove ECHO from the command line starting DTExec.exe and save the batch file.

Open D:\Conversion\log\ScriptOutput.log in a text viewer/editor and it contains the information of all three batch file executions.

There is just one issue remaining. It could happen that one older temporary log file is appended twice to summary log file. This happens on execution of this batch file two or more times within 30 seconds on currently write-protected summary log file and the write lock is removed while the running instances of the batch file are all in the retry loop and the 1 second timeout ends by chance in at least two running instances of the batch file nearly at same time.

I don't know how often the batch file is executed and how long DTExec.exe takes to finish the task. So I don't know if the information duplication in summary log file could occur ever on real usage of the batch file. The retry count can be decreased for example from 30 to 5 to avoid that this most likely very rare case occurs. However, no information is lost when this case occurs; just one execution of the batch file is logged twice in the summary log file.


It is of course much easier to execute the commands and simply loose all information if the summary log file is currently write-protected.

@echo off
setlocal EnableDelayedExpansion
(
echo/
echo %date% %time% BEGIN OUTPUT FOR MoveTransDataToReporting.dtsx Script
echo/

"C:\Program Files (x86)\Microsoft SQL Server\120\DTS\Binn\DTExec.exe" /FILE "D:\Conversion\sql\MoveTransDataToReporting3Years.dtsx" /CHECKPOINTING OFF /REPORTING EWCDI 2>&1

echo/
echo !date! !time! END OUTPUT FOR MoveTransDataToReporting.dtsx Script
echo **************************************************************************************************************************************
) >>D:\Conversion\log\ScriptOutput.log
endlocal

Delayed expansion is enabled as required to reference the dynamic environment variables DATE and TIME the second time with using delayed environment variable expansion with !date! !time!.

The Windows command processor replaces each environment variable reference using syntax %variable% by current value of referenced environment variable already on parsing an entire command block starting with ( and ending with matching ) before executing the commands inside the command block. So using twice %date% %time% in this command block without usage of delayed expansion would result in having the same date and time recorded twice in the log file.

It is also possible to suppress the access denied error message output on log file being currently write-protected by redirecting it to device NUL with using one more command block.

@echo off
setlocal EnableDelayedExpansion
((
echo/
echo %date% %time% BEGIN OUTPUT FOR MoveTransDataToReporting.dtsx Script
echo/

"C:\Program Files (x86)\Microsoft SQL Server\120\DTS\Binn\DTExec.exe" /FILE "D:\Conversion\sql\MoveTransDataToReporting3Years.dtsx" /CHECKPOINTING OFF /REPORTING EWCDI 2>&1

echo/
echo !date! !time! END OUTPUT FOR MoveTransDataToReporting.dtsx Script
echo **************************************************************************************************************************************
) >>D:\Conversion\log\ScriptOutput.log ) 2>nul
endlocal

Note: The command line with DTExec.exe contains at end only 2>&1 in the two simplified batch files posted above because of everything written to handle STDOUT with command block is redirected and appended (if possible) to the log file.


For understanding the used commands and how they work, open a command prompt window, execute there the following commands, and read entirely all help pages displayed for each command very carefully.

  • del /?
  • echo /?
  • endlocal /?
  • for /?
  • goto /?
  • if /?
  • ping /?
  • set /?
  • setlocal /?
  • timeout /?
  • type /?
  • wmic /?
  • wmic os /?
  • wmic os get /?
  • wmic os get localdateime /?

See also

Mofi
  • 46,139
  • 17
  • 80
  • 143
1
set "LogFile=ScriptOutput.log"

:retry
((
    REM Do stuff here...
    verify>nul  &:: Sets errolevel to 0. This is important
)>>"%LogFile%" 2>&1)2>nul || (set "LogFile=con" & echo Log file inaccessible, Bypassing LogFile... & goto :retry)

The last command in the LOG block must explicitly set errorlevel to 0, so the error condition will be executed only if the LogFile can not be opened. verify>nul will do the job. any other command that sets errorlevel to 0 can be used instead. ex: (call ) (note the space between call and closing bracket.)

The outer block will hide the error message related to opening LogFile, so a custom message can be displayed in the error condition block, if desired.

It will retry the process by displaying output to console by setting the LogFile to con. It can be redirected to nul or another file if needed.

sst
  • 1,443
  • 1
  • 12
  • 15