Thursday, 18 July 2013

Redirecting Output to Dated Log Files

The other day the requirement came up to run a scheduled task to copy some data from a production to development machine to archive some data for testing later. Naturally ROBOCOPY was going to do the heavy lifting, but if there’s one thing I’ve learnt about scheduled tasks it’s that you’ll always want to capture the output to a log file, if it’s not done already by the tool, and to annotate that output with extra details like the start/end date & time.

Redirecting Output

Taking a leaf out of my own book, or more specifically my recent “In The Toolbox” article on wrapper scripts in the current C Vu, I’d probably wrap the command in a batch file to give myself a little wriggle room and then capture the entire output by relying on the command interpreter to do the redirection. For example the task definition might look like this:-

C:\Program Files\My Service\ProdToDevCopy.cmd >> D:\My Service\Log\ProdToDevCopy.log 2>&1

As a general rule I always append to log files rather than clobber them, so that you maintain a history of failed runs when they occur. The “2>&1” bit on the end [1] redirects the stderr stream to stdout so that it goes in the same log file. I find two log files a bit of a pain, especially when you’re trying to track down why it failed. Ands I often forget to add this, which is another reason why I’m writing this down now.

Dated Log Files

When a task runs very frequently using a single log file gets unwieldy, not least because it makes archiving old log files impossible. Consequently logging to a file based on the current date is usually a sufficient way to split them. Another reason to implement the scheduled task command as a batch file is that what you’re really invoking is a copy of the command interpreter (as CMD.EXE /C)and so you have access to other features too, such as the lesser known “substring” expansion feature for variables. If you type C:\> HELP SET you’ll find out all the details.

In this instance we want to take the output of the %DATE% variable, split it into its separate fields and then recombine them again to make an ISO style date (YYYY-MM-DD) [2]. On my machine the output for %DATE% is in the common DD/MM/YYYY format:-

C:\> echo %DATE%

Before going any further it should be apparent that this is not going to work on an arbitrary machine because different locales mean that the source date format will vary. However in the context of an enterprise application server where a lot of things can often be taken for granted this can work just fine.

The basic format for a variable expansion is this:-


The offset and length can both be negative meaning that you can index from the end of the string and take all but a few characters. And you can omit them too which implies an index of 0 and the entire string length.

Just using the indexing gives you at least two usefully different ways to represent the window:-

YYYY = %DATE:~6,4% or %DATE:~-4%
MM   = %DATE:~3,2% or %DATE:~-7,2%
DD   = %DATE:~,2%  or %DATE:~-10,2%

And so applying the shortest form of each we can concoct a minimal pattern for our date:-

C:\> echo %DATE:~-4%-%DATE:~3,2%-%DATE:~,2%

Plugging this back into the (shortened) original script command line gives us this:-

ProdToDevCopy.cmd >> D:\Log\ProdToDevCopy.%DATE:~-4%-%DATE:~3,2%-%DATE:~,2%.log 2>&1


[1] And it has to go on the end too. If you put it before the redirection it won’t work. For an extensive run-down of redirection options see this page.

[2] By using an ISO style date in log file names they become sorted by date by default which can make life easier in some scenarios.

No comments:

Post a Comment