Add Timestamps to stdout and stderr Piped to Log Files
Date: 11 May 2018
Category: Scripting
Tag: Batch
The scheduled execution of a task was performed on a Windows Server by calling a batch script from Task Scheduler. I wanted to use Splunk to monitor the results of this task, and to send me an alarm whenever an error occured.
Piping stdout and stderr to a log file was perfectly simple:
for /f "tokens=1-2 delims=:" %%a in ("%TIME%") do (set mytime=%%a%%b)
for /f "tokens=1-3 delims=/" %%a in ("%DATE%") do (set mydate=%%a.%%b.%%c)
set log="%home%\logs\log-%mytime%-%mydate%.log"
@echo %DATE% %TIME% - INFO - Running process x > %log%
{run process x} >> %log% 2>&1
if %ERRORLEVEL% NEQ 0 (
@echo %DATE% %TIME% - ERROR - An error occurred running process x >> %log%
@echo %DATE% %TIME% - ERROR - Exiting process >> %log%
exit /b 1
)
@echo %DATE% %TIME% - INFO - Process x completed successfully >> %log%
However the outut from {run process x} >> %log 2>&1%
would not be prepended by timestamps:
Fri 05/11/2018 14:06:42.68 - INFO - Running process x
This
is
the
output
Fri 05/11/2018 14:06:42.81 - INFO - Process x completed successfully
This made parsing the log file with Splunk more challenging.
Loopy
This Stack Overflow topic led me to the solution:
for /f "delims=" %%i in ('{run process x}}') do (
@echo %DATE% %TIME% - INFO - %%i >> %log% 2>&1
)
This gave me the perfectly formatted log files I desired, making parsing the files with Splunk significantly easier:
Fri 05/11/2018 14:06:42.68 - INFO - Running process x
Fri 05/11/2018 14:06:42.78 - INFO - This
Fri 05/11/2018 14:06:42.78 - INFO - is
Fri 05/11/2018 14:06:42.78 - INFO - the
Fri 05/11/2018 14:06:42.78 - INFO - output
Fri 05/11/2018 14:06:42.81 - INFO - Process x completed successfully