greater than

expect-lite


Automation for the rest of us

Tips and Techniques: Simplifying the Debugging of expect-lite scripts



Introduction

Over the years of using and improving expect-lite, a few debugging techniques have proven quite useful. The purpose of the document is to provide some additional information to assist the user of expect-lite in debugging scripts, and tips to make expect-lite script writing even easier. Familiarity with expect-lite is assumed, if not, please refer to the expect-lite documentation.

Contents

Some Tips and Techniques for expect-lite:

Interact - setting breakpoints

Interact may be the quickest, easiest, and overall best debugging aid. It is equivalent to setting a breakpoint in the script. Interact is a mode which turns control of the keyboard over to the user, so that one may type directly to the process on the remote host With version 3.5.0 there are two methods to invoke Interact: programmatic, and instant-interact.

Programmatic Interact is called in the script with the following command:
*INTERACT
Expect-lite will pause at this point in the script, and connect the keyboard to the remote session (which may be at a prompt). Any command may be entered and responses observed. Typing '+++' (3 pluses) will return control to the script, and it will continue. This is very helpful for automation assist, allowing the script to perform complicated setup commands, before turning control over to the user for an interactive session.

The other method is instant-interact. This feature requires a tcl package Tclx to be installed, and will automatically be enabled when the package is present. With the feature enabled, the user can press '^\' (control+backslash) at anytime creating a breakpoint on the fly. This is the easiest, and fastest way to debug a script.

Debugging with the IDE

To make debugging of scripts even easier, both methods of interact support a limited expect-lite Integrated Debugger Environment (IDE). In this IDE, expect-lite script commands can be typed, even assigning variables and displaying them, inside the paused script, for example:
$MYVAR=today

*SHOW VARS
Var:0 Value:0
Var:MYVAR Value:today
Var:TEST Value:/proc/cpuinfo

>>pwd
pwd
/home/user

Fail then Interact

There is a secret back door to expect-lite, which reverses a script failure. Instead of halting and failing, the script can use the fail script (a special include script) mechanism to include a debugging aid.

Add the following debugging script near the beginning of the script which is being debugged:
*~debug.inc

The actual debugging script is as follows:
#
# debug.inc
#
*INTERACT
>
# allow script to continue
!set _el(continue) 1
>
; === Continuing Script
>

When a script fails, it will print the usual command failed, and what it was expecting, then expect-lite will call the fail script (debug.inc). Once debug.inc is run, it drops the user into interact mode. This provides the opportunity to fix the error (perhaps there was a missing command). Once the fix is done, typing '+++' will return from the interact session and the script will continue (in this case, still debug.inc).

Now this is where the secret backdoor part comes in. There is a line of embedded expect in debug.inc:
!set _el(continue) 1
This tells expect-lite to not halt the test, but in fact, to continue the test as if no failure had occurred (very sneaky). Lastly, debug.inc prints into the log that it is continuing the script, and at the end of debug.inc, control is returned to the buggy script right after the failure point and continues.

This little script is such a great tool for debugging, that we found it invaluable and put it into all our scripts. Note: be sure to remove the reference to debug.inc before putting the now-bug-free script into production.

Finding In... Verbose

Since most expect-lite scripts are composed of > and < lines, it can be difficult to understand why expect-lite isn't finding the desired text. Using the -vv or --verbose option (in version 3.1.4 or later) will display the string that is to be matched (find) and the entire string that is being searched (in).

For example, for the given expect-lite code:
>cat $tmp_file
<Proto \[LAN\]Addr:Port => Addr:Port \[WAN\]Addr:Port <= Addr:Port
<6[ \t]+[0-9a-f:]{11,14}[ \t]+[0-9a-f]{8}:22
With the --verbose option, the output will appear with the additional lines:
cat /proj/regression/tmp/junk
Dec 31 1969 19:43:12:025952:INFO :CLI :cli.c:2945:_cli_handle_short_cmd:
Execute command: "fwdstat".
Proto [LAN]Addr:Port => Addr:Port [WAN]Addr:Port <= Addr:Port
6 c0a85001:41696 c0a81401:22 c0a81401:22 c0a81402:32770

find<<Proto \[LAN\]Addr:Port => Addr:Port \[WAN\]Addr:Port <= Addr:Port>>
in<<cat /proj/regression/tmp/junk
Dec 31 1969 19:43:12:025952:INFO :CLI :cli.c:2945:_cli_handle_short_cmd:
Execute command: "fwdstat".
Proto [LAN]Addr:Port => Addr:Port [WAN]Addr:Port <= Addr:Port>>

find<<6[ \t]+[0-9a-f:]{11,14}[ \t]+[0-9a-f]{8}:22>>
in<<
6 c0a85001:41696 c0a81401:22>>
Both the 'find' and 'in' text are wrapped in << >> to show any line feeds. The 'find', if successful, will almost always be at the bottom of the 'in' text. Often when there is a unexpected failure, the  '<' is defined too broadly, and expect-lite has matched an unexpected piece of 'in' text. (see Define '<' narrowly)

As of expect-lite version 3.1.4, -vv or --verbose will also display 'find and 'in' for dynamic variable capture, thus providing a bit more information to assist in debugging this feature as well.

As of expect-lite version 3.5.0, -vv or --verbose will display all warnings and debug information (including user defined prompt debug info)

Showing Variables & Values with *SHOW VARS

Sometimes when troubleshooting a script, it is really useful to display the value of an expect-lite variable. The easiest method to display a variable is to use the printable comment ';'  For example, there is a variable named '$max', by adding the following line to the script, $max will be dereferenced and displayed:
; The value of max is:$max
The above method works well for a few variables, but it may be neccessary to view all the expect-lite variables. In previous versions of expect-lite, a script (show_vars.inc) was required to view all variable values. As of version 3.5.0, the expect-lite directive: *SHOW VARS now performs the same function.

All variables can now be displayed by using the line:
*SHOW VARS
The include script is written in embedded expect and will walk the array of expect-lite variables, and print their respective values. The output will appear like the following:
 === Show all Vars Defined

Var:count Value:14
Var:first Value:this is a regression test line
Var:gen10 Value:test10
Var:gen11 Value:test11
Var:gen12 Value:test12
Var:gen13 Value:test13
...
Var:mac_da12 Value:38:8B:50:49:AE:0D
Var:mac_da13 Value:38:E4:EB:0C:DE:4B

*SHOW VARS can also be used with *INTERACT and instant-interact to view the values all assigned variables.

Define '<' narrowly

Do not define '<' too broadly. For example, DO NOT use the following:
<\n.*
The above defines 0 or more of any character after a newline. This will match just about anything, and more than likely not what is intended.

Instead use a more specific '<'. If the expected string is only composed of numbers at the beginning of a line, use:
<\n[0-9]+
Use with the --verbose option to see what is being matched, and to assist in refining the '<' statements.

Decreasing the log chatter

After one's scripts are succesfully debugged, it may not be desireable to see all the log chatter which expect-lite produces, such as warnings, conditional reports, dynamic variable assignments. This chatter can be reduced by using the expect-lite logging directives at or near the beginning of the script, such as:
*NOWARN
If while debugging the script, it is desirable to see the additional logging info (chatter), it can be turned on via the command line with the -v parameter:
expect-lite -v r=myhost c=myscript

Removing Colour from output

In an automated environment, it is probably not desirable to have ANSI color sequences embedded in the logs. Although it is possible to use the expect-lite directive *NOCOLOUR in each script to turn off colour, there is an easier way. Define the terminal type to a dumb terminal, such as tty.
export TERM=tty
expect-lite will detect the dumb terminal type and turn off colour output automatically.

General Tips

Here are some simple tips when script writing:
  • Use reasonable timeouts, if 30 seconds is needed to get a response, set the timeout at 45 or 60 seconds, not 600.
    • There is no cost to changing the timeout, timeout values can also be variables
  • Beware of expect-lite using regex, when creating lines like: <0.005 secs (5 micro secs)
    • The parentheses is used by the regex engine, instead escape these characters: <0.005 secs \(5 micro secs\)
    • or use '<<' which does not use regex, and does not require escaping: <<0.005 secs (5 micro secs)
  • Use the expect character '<' or '<<' often. Check for valid results when possible. A script which expects nothing will never fail!
  • Use printable comments ';'  and ';;' often. Think of it as writing a note to oneself, it will make reading log files much easier. As of version 3.7.0 printable comments will be coloured blue (this is user configurable).

Summary

By using these troubleshooting aids, it should be even easier to write and debug expect-lite scripts. Feel free to send me any tips. cvmiller at gmail dot com

Why Expect-lite

Expect-lite was written to create quick and easy automation of repetitive tasks.



31 July 2010
http://expect-lite.sourceforge.net/

this document for version 3.7.0 or later