Wednesday, November 19, 2014

Sawing Logs

Sawing Logs the way you like them
Recording what happened for later review is called logging. For years expect-lite lacked native logging, and relied on other programs like 'script' or 'tee' to record the output. Logging was added to make it easier to record just the parts you might want to keep for later.

expect-lite uses directives to control behavior of operation. Directives always start with an asterisk, and all CAPS, like *INFO. The *LOG, *NOLOG and *LOGAPPEND directives added native logging support in 2013. Like all directives, the log commands can be used on the command line when starting a script, or within the script to just log the desired portion.

*LOG

The *LOG will automatically create a log file with the <script_name>.log in the script directory. But *LOG can also take a path/filename parameter to log to a different directory.
$path=/tmp
; === get today's date
>date %F
+$today=\n(\d+-\d+-\d+)
*LOG $path/$arg0-$today.log
>do stuff


*NOLOG

And the *NOLOG stops the logging. For example, perhaps there is a while loop that is polling for some event, you don't really need to see that it polled 500 times in the log, you just want to see (in the log) what happens after the event.
...
*LOG $path/myfile-$today.log
>do stuff
*NOLOG
[ $state != $event
   ; poll for event
   >show event
   +$state=(enabled|disabled)
]
*LOGAPPEND $path/$arg0-$today.log
...

And *LOGAPPEND will append to an exiting log file, or create a new file, if there is no existing file.

What is logged

The *LOG log file will capture everything that is seen on the terminal screen, expect-lite messages such as *INFO, *WARN, commands typed in during an *INTERACT (a breakpoint), and all standard out, including colour. (hint use *NOCOLOUR to disable colour output).

Plays well with Instant Interact

Why not just use 'script' or 'tee' commands to record the script output. No reason, if that it working for you. However *LOG provides better control over what goes into the log file. Additionally, I had real problems using 'tee' and Instant Interact (creating a breakpoint on the fly) with Ctrl+\, as it would terminate the 'tee' command (and in turn the running script). Using native logging with *LOG allows you to use Ctrl+\ (control backslash) at any point during the script, giving you immediate access to the running script without having to preset a breakpoint.

So go ahead and saw those logs up anyway you like, because expect-lite is automation for the rest of us.

Note 1: the pre-defined variable $arg0 holds the script name
Note 2: for those who don't require 'U's in colour, *NOCOLOR will also work