In the last couple of chapters, I described how to write patterns. Clearly there are some tricky issues of which you have to be aware. Writing effective patterns is a challenging art for several reasons.

First, you have to know the rules for constructing patterns. Second, you have to understand the rules for expressing them in Tcl. Third, you have to know what characters are in the string you expect. Misunderstanding any one of these steps can cause you to write patterns that do not match.

When patterns do not match as intended, a common symptom is that the script executes very slowly. For example, the following is a fragment of a script to log in. It ought to execute quickly.

expect "Login: "
send "don
"
expect "Password: "
send "swordfish
"

However, on a typical system this fragment takes 20 seconds to execute instead of one or two seconds. There are two problems. The first is with the patterns. The first pattern says to expect "Login:" but on a typical UNIX system the prompt is "login:“.

Instead of matching, the script waits for more input for another 10 seconds (because that is the default timeout). After 10 seconds, expect times out. Since there is no timeout action, the user is not informed that the pattern failed to match. The expect simply returns and control passes to the next command in the script.

This kind of mistake is not uncommon. Part of the reason is that on a UNIX system, the default login prompt starts with a lowercase letter while the password prompt starts with an uppercase letter. This kind of inconsistency, rampant in many interactive interfaces, is ignored by most users and naturally shows up in scripts like these.

The second problem is due to another user-interface inconsistency. There is a space character at the end of the "Password:" pattern. But the actual prompt received is "Password:“, which does not have a space at the end! This type of incorrect pattern is an easy mistake to make because most prompts include a trailing space—but not the one for the password. Repeating the earlier logic, the script waits for another 10 seconds.

Scripts with these kinds of errors may work, but with snail-like speed. One way to find out the problem is to ask Expect what it is doing internally.

The command "exp_internal 1" causes Expect to print diagnostics describing some of its internal operations. Among other things, this includes the comparisons that occur within the expect command. Here is the script using "exp_internal 1" along with a telnet command.

spawn telnet uunet.uu.net
exp_internal 1
expect "Login: "
send "don
"
expect "Password: "
send "swordfish
"

When run through the first expect-send sequence, the output starts out like this:

spawn telnet uunet.uu.net
expect: does "" (spawn_id 5) match glob pattern "Login: "? no
Trying
expect: does "Trying " (spawn_id 5) match glob pattern "Login: "? no
192.48.
expect: does "Trying 192.48." (spawn_id 5) match glob pattern "Login: "? no
96.2 ..
expect: does "Trying 192.48.96.2 .." (spawn_id 5) match glob pattern "Login: "? no
.

What you see is the normal output from Expect plus the diagnostic output describing exactly what is in the input buffer and what the current patterns are. Each line that begins with "expect: does" prefaces a comparison. The current input buffer follows, surrounded by double quotes, and then the pattern that is being used, also in double quotes. For instance, expect initially starts out with nothing in the input buffer and so you see:

expect: does "" (spawn_id 5) match glob pattern "Login: "? no

Then the string "Trying" arrives. This is part of the string that telnet normally prints when it opens a connection. Expect adds this to the input buffer and retries the pattern:

expect: does "Trying " (spawn_id 5) match glob pattern "Login: "? no

After each test, expect prints the word "no" if the match was unsuccessful or "yes" if it was successful. The (spawn_id 5) is an indication of which spawned process was participating in this match. I will describe the particular meaning of this further in Chapter 10 (p. 229). For now, I assume there can only be one process, and I will omit the process identifier in the rest of this example.

Skipping ahead, you can eventually find Uunet’s greeting message:

UUNET Communications Services (uunet)
expect: does "Trying 192.48.96.2 ...
Connected to uunet.uu.net.
Escape
character is `^]'.

UUNET Communications Services (uunet)



"
match glob pattern "Login: "? no

Notice how the input buffer has been converted to a kind of backslash-like representation. That is, carriage-returns are displayed as " " and linefeeds as " “. This is very helpful if you need to match these explicitly.

Immediately after this, Uunet sends its login prompt—for which the script has been waiting.

login:
expect: does "Trying 192.48.96.2 ...
Connected to uunet.uu.net.
Escape
character is '^]'.

UUNET Communications Services (uunet)



login: "
match glob pattern "Login: "? no

Now you can see the login prompt, and it becomes obvious that the pattern will never match. Sure enough, expect sits for the remaining time and then finally reports that it timed out.

expect: timed out
send: sent "don
"

The send command similarly produces messages describing what it has done. In this case, it has sent the string don back to the process.

Now that the script has sent the username, it immediately goes on to the next step—waiting to be prompted for the password:

expect: does "Trying 192.48.96.2 ...
Connected to uunet.uu.net.
Escape
character is '^]'.

UUNET Communications Services (uunet)



login:
" match glob pattern "Password: "? no
don

expect: does "Trying 192.48.96.2 ...
Connected to uunet.uu.net.
Escape
character is '^]'.

UUNET Communications Services (uunet)



login:
don
" match glob pattern "Password: "? no

At this point, the password has not appeared. What has appeared, however, is the username that the script sent earlier. You see the username come back simply because the remote side is echoing it. This is normal and is the reason why you see most of your own keystrokes when you type them. By comparison, the password will not be echoed.

Password:
expect: does "Trying 192.48.96.2 ...
Connected to uunet.uu.net.
Escape
character is '^]'.

UUNET Communications Services (uunet)



login:
don
Password:" match glob pattern "Password: "? no
expect: timed out
send: sent "swordfish
"

You can now see very clearly that the input buffer contains "Password:“—without a space—but the pattern is looking for "Password:“—with a space. The pattern fails to match of course. And if you look closely, you can even see that the login prompt is still in the input buffer. That is because it was never matched and so never got removed from the buffer either.

The current expect command eventually times out, and the script continues with the next line. If the rest of the script works, the errors at the beginning do not add up to much; however, they really should be fixed. At the very least, they unnecessarily slow down the script. At the very worst, the script could send things at times when it does not make sense, ending up with unpredictable behavior and an unreliable script. Remember this as you write scripts. If your script pauses for a significant amount of time, even though the prompt it is looking for has already come, there is almost certainly something going wrong that you should investigate.

Here is another version of the script. It is worth studying because it works quite differently than a straightline script where one expect command follows another rigidly. In this script, there is a while loop enclosing a single expect command in which all the patterns are listed together. The sole advantage to doing so here is that you need only write one timeout action rather than a timeout in every expect command. In some situations, this kind of processing is very useful toward simplifying the overall control while adding flexibility. But in Chapter 11 (p. 255) I will show better ways of economizing on the number of times you have to write timeout.

More importantly, the patterns are correct this time. The diagnostic output will show the two patterns being matched against the same input each time, and ultimately one pattern will always be matched. I have also added the -indices flag (see Chapter 5 (p. 123)) so that you can see its effect.

spawn telnet ftp.uu.net
exp_internal 1
set timeout 30
while 1 {
    expect {
        -indices "login: " {
            send "don
"
        } -indices "Password:" {
            send "swordfish
"
        } timeout {
            puts "warning: timed out"
        }
    }
}

The script starts the same way as before: by spawning a telnet process.

spawn telnet ftp.uu.net
expect: does "" match glob pattern "login: "? no
"Password:"? no

expect starts out by attempting to match both patterns against an empty buffer since nothing is received immediately. Here, they both fail. The string "trying" arrives and then some more input dribbles in. In each case, the patterns fail to match.

Trying
expect: does "Trying " match glob pattern "login: "? no
"Password:"? no
192.48.96.9 ...
expect: does "Trying 192.48.96.9 ...
" match glob pattern "login: "? no
"Password:"? no
Connect
expect: does "Trying 192.48.96.9 ...
Connect" match glob pattern "login: "? no
"Password:"? no
ed to f
expect: does "Trying 192.48.96.9 ...
Connected to f" match glob pattern "login:
"? no
"Password:"? no
tp.uu.net.
Escape character is `^]'.
expect: does "Trying 192.48.96.9 ...
Connected to ftp.uu.net.
Escape character
is `^]'.
" match glob pattern "login: "? no
"Password:"? no

Finally you can see Uunet’s greeting message. The script is still looking for "login:" (and "Password:" for that matter).

SunOS UNIX (ftp)
expect: does "Trying 192.48.96.9 ...
Connected to ftp.uu.net.
Escape character
is `^]'.


SunOS UNIX (ftp)



" match glob pattern "login: "? no
"Password:"? no
login:
expect: does "Trying 192.48.96.9 ...
Connected to ftp.uu.net.
Escape character
is `^]'.


SunOS UNIX (ftp)



login: " match glob pattern "login:
"? yes

Here is the first successful match. Expect prints out yes after the pattern that has been matched and then prints the internal assignments that are made before any actions are executed.

expect: set expect_out(0,start) "103"
expect: set expect_out(0,end) "109"
expect: set expect_out(0,string) "login: "
expect: set expect_out(buffer) "Trying 192.48.96.9 ...
Connected to
ftp.uu.net.
Escape character is `^]'.


SunOS UNIX
(ftp)



login: "

Now the corresponding action is executed, sending the string don to the process.

send: sent "don
"
expect: does "" (spawn_id 5) match glob pattern "login: "? no
"Password:"? no
don
expect: does "don
" (spawn_id 5) match glob pattern "login: "? no
"Password:"? no
Password:
expect: does "don
Password:" match glob pattern "login: "? no
"Password:"? yes
expect: set expect_out(0,start) "7"
expect: set expect_out(0,end) "15"
expect: set expect_out(0,string) "Password:"
expect: set expect_out(buffer) "don
Password:"
send: sent "swordfish
"

Uunet responds with a prompt for the password. This is immediately matched by the script and the password itself is sent back.

You may have noticed that the script does not do anything differently after sending the password. It is rather dumb—it just continues looking for "login: " or "Password:" whether it logs in successfully or not. Nonetheless, it suffices to show the kind of diagnostics you can get from the exp_internal command.

In Chapter 6 (p. 151), I described the -notransfer flag. Together, the -notransfer flag and the internal diagnostics should be very helpful for debugging most of the pattern matching problems you encounter.

In long scripts, it is convenient to be able to turn Expect’s internal diagnostics off. You can do this with the command "exp_internal 0“. You can use the exp_internal command to turn the diagnostics off and on as you like. For example, it is common to surround just a small group of commands or even one command with exp_internal commands as you narrow down where the problem lies in a script.

exp_internal 1
expect
exp_internal 0

You may also find it convenient to conditionalize the use of exp_internal. For example, you can set a global variable that controls whether all of the exp_internal commands are actually executed. The following code permits "exp_internal 1" commands in the code to execute only when the variable debug_enable is nonzero. The idea is that this variable is set once—which is much easier than adding or commenting in and out commands scattered throughout a script. (In Chapter 9 (p. 219), I will describe how to get this effect on a script-wide basis without changing the script at all.)

if $debug_enable {exp_internal 1}
expect . . .
exp_internal 0
send . . .
expect . . .
if $debug_enable {exp_internal 1}
send . . .
expect . . .
exp_internal 0

The "exp_internal 0" commands do not have to be conditionalized. It is not an error to execute "exp_internal 0" even if diagnostics have not been enabled. In this case, "exp_internal 0" is just ignored.

An even more convenient way to control diagnostic output is to define procedures such as the following one:

proc debug_on {} {
    global debug_enable
    if {$debug_enable} {exp_internal 1}
}

Now the code would look slightly simpler. Here is just the beginning of the code above rewritten to use debug_on and a similar procedure debug_off.

debug_on
expect
debug_off
send . . .
expect . . .
debug_on

The advantage to this, besides being simpler to write, is that the variable debug_enable will also be accessible because of the global command in the procedure debug_on. With the earlier technique, global commands have to be added to every procedure containing the "if $debug_enable" test.

Enabling Expect’s internal diagnostics can cause a tremendous amount of output to be produced since many of the internal actions and decisions that Expect makes are printed out. The process of producing diagnostic output does not change any of the external behavior of Expect except for what is shown at the terminal. Since Expect continues to display the output of whatever process it controls as well as the diagnostic output, the total effect can be very disorienting, sometimes making it difficult to figure out what is normal process output and what is diagnostic output. It is possible, however, to separate the two output streams so that they are readable.

It is important to understand that normal terminal output consists of two “streams of output”. One is called the standard output and the other is called the standard error. Most program output gets written to the standard output but error messages get written to the standard error. The usual shell output redirection (”program > output-file“) redirects only the standard output. This allows programs to print error messages to the user and not have them go down the pipe where they will not be seen. Try invoking grep, for example, on a non-existent file while redirecting the output. You will still see the error message.

Expect works the same way. Most output is sent to the standard output while the diagnostic output is sent to the standard error. These can be separated by shell redirection when the Expect program or script is started. For example, you might want to send the diagnostics to the file "diag“. In the Bourne or Korn shell, you do this by starting your Expect script like this:

$ scriptname args 2> diag

Most people consider the C-shell syntax so peculiar that they find it easier to explicitly run one of the other shells in such situations and type the previous command. If you do need to stay in the C-shell for some reason, use the following command:

% (scriptname args > /dev/tty) >& diag

Once you have redirected the output, you can watch it from another window, in this case by executing the command "tail -f diag" which prints out any new diagnostics as they are written to the file. The command "tail -f diag | more" lets you read the diagnostics before they roll off the screen. If there are not that many diagnostics or if you do not need to save them in a file, you might consider writing them directly to another window. Get the name of the window where you want the output to appear by executing the tty command in that window. The response will be the name of a terminal device such as "/dev/ttyp1“. Now start the script in the other window as:

$ scriptname args 2> /dev/ttyp1

Redirecting the standard error can introduce one tiny problem into your interaction with Expect. Namely, any real errors that occur in your script or session are also sent to wherever you have redirected the standard error. You cannot see them in the window from which you started Expect even if you normally see them there. Fortunately, this problem only arises when doing script development since production scripts should not produce any errors. Just remember to watch wherever you have the standard error redirected.

It is possible to achieve all sorts of effects by playing games with redirection. One of the more useful things is to log both the standard output and standard error to a file. Expect provides this same capability in a more flexible way than can be achieved with redirection. This is done using the exp_internal command with the -f argument. An output file name must follow the -f along with a 0 or 1. The 0 or 1 disables or enables the generation of diagnostics just as before. However, the standard output and standard error is still logged to the file even if a 0 is supplied to exp_internal.

To summarize:

The form "exp_internal -ffile 0" is particularly useful because Expect appears to act just as if no diagnostics were being generated, even though it is actually writing the usual output and diagnostics to a file at the same time. You can put this particular command in production scripts and users will not be affected by the command. If a user then reports a bug, you can check the file and see exactly what went wrong.

As before, exp_internal commands can be placed around pieces of code to limit the amount of diagnostics they produce. Each exp_internal command closes any previous file that was named by an exp_internal command. So you can log different parts of a script to different files. When the script ends, any open exp_internal file is closed.

In the previous section, I showed how to generate, control, and suppress diagnostics produced by Expect. All output produced by spawned programs, however, appears on Expect’s standard output. It is possible to redirect or suppress this as well, but it is done in a different way.

Figure 7-1. Inside of Expect, the standard output and standard error of a spawned process are joined together and ultimately appear as the standard output of Expect

The standard error and standard output of a spawned process are joined together inside of Expect. This is done before pattern matching occurs so that patterns must account for both streams appearing simultaneously. The reason this is done is partly philosophical and partly practical.

Philosophically speaking, interactive programs always have the outputs merged together anyway—on the screen. It is impossible for users to visually distinguish between characters appearing on the standard output versus the standard error. Their minds make up for it by scanning the output, both for normal output and errors at the same time. If humans can do it, then so can scripts. This is the philosophy that Expect takes.

Practically speaking, few interactive programs send things to the standard error. What is the point? A user is watching the standard output anyway. The user sees the error whether it appears on one stream or the other. (When was the last time you ran ftp, for example, with either output stream redirected?) Ironically, Expect could be cited as a counterexample to this. It goes out of its way to send its errors to the standard error. However, it does this specifically to assist in the case when it is run non-interactively. In such a situation, the standard output could very understandably be redirected. But used interactively, the separation of standard error and standard input is not particularly useful.

I showed earlier how the standard error of Expect can be redirected. Similarly, so can the standard input. This is done using the traditional "<" notation. However, this kind of redirection is crude. It can only be done once, when starting Expect, and the redirection can never be changed after that.

In Expect scripts, it is very useful to hide the underlying dialogue, perhaps substituting new output. Sometimes it is useful just to show parts of the dialogue. You can do this with the log_user command. "log_user 0" stops the output of the spawned process from appearing in the standard output of Expect. "log_user 1" restores it.

The following script verifies email destinations at remote hosts by exercising the vrfy command supported by SMTP, a mail transfer protocol commonly used on the Internet. The script takes an email address as an argument.

#!/usr/local/bin/expect --

regexp (.*)@(.*) $argv ignore user host
spawn telnet $host smtp
set timeout −1
expect -re "220.*
"
send "vrfy $user
"
expect -re "(250|550).*
"

The first command in the script extracts the user and host names from the original argument. This is done using the very same regexp command that I used as an example in Chapter 6 (p. 135). The remainder of the script performs the interaction with the remote host.

The script is named vrfy. When I run it, here is what appears:

% vrfy [email protected]
spawn telnet next.com smtp
Trying 129.18.1.2 ...
Connected to next.com.
Escape character is '^]'.
220 NeXT.COM Sendmail NX5.67d/NeXT0.5-Aleph-amm ($Revision: 1.4 $ $State: Exp $)
ready at Thu, 1 Apr 93 21:32:19 -0800
vrfy jobs
250 <jobs>

By adding "log_user 0" to the script and giving the final expect command an explicit action, the output is simplified dramatically. Here is the new version using log_user.

#!/usr/local/bin/expect --

log_user 0
regexp (.*)@(.*) $argv ignore user host
spawn telnet $host smtp
set timeout −1
expect -re "220.*
"
send "vrfy $user
"
expect "250" {puts "GOOD"} 
       "550" {puts "BAD"}

Here is what it looks like when I run it with a few test cases.

% vrfy [email protected]
GOOD
% vrfy [email protected]
BAD

This new version is just as functional, and the output is much easier to read.

Output generated by the puts command still appears in Expect’s standard output. The effect of "log_user 0" only disables output from the underlying spawned process.

send commands are not directly affected by log_user. The characters still go to the spawned process. However, the same characters normally show up eventually in the output of a spawned process because of echoing. While the echoing is still done by the spawned process, "log_user 0“, as before, prevents the characters from being sent on to Expect’s standard output. So it may seem that log_user has an effect on send, but this is true only indirectly.

As an example, suppose a connection to a remote host has been spawned and you want to get the remote date, but without seeing the date command itself echoed. A common error is to write:

log_user 0                    ;# WRONG
send "date
"                 ;# WRONG
log_user 1                    ;# WRONG
expect -re .*
               ;# WRONG

When run, the log_user command has no effect because Expect does not read the echoed "date" until the expect command. The correct way to solve this problem is as follows:

send "date
"
log_user 0
expect -re "
([^
]*)
"    ;# match both "date" cmd
                              ;# and actual date
log_user 1
puts "$expect_out(1,string)"  ;# print actual date only

In this rewrite, the expect command skips over the date command string by matching for the echoed back. The pattern also matches the next line, which is the actual date. The parentheses select just the information wanted (the date), which can then be printed with an explicit puts command. (If you are sending a lot of commands to a remote shell it may be more convenient to just disable all echoing in the first place. I will demonstrate this in Chapter 12 (p. 269).)

One other thing suppressed by "log_user 0" is the side-effect of spawn. The spawn command normally echoes itself to the standard output. This is disabled with "log_user 0“.

Because output describing everything going on underneath can be surpressed, it is possible to write scripts that produce no output at all. Instead, a script can cause side-effects such as writing files or setting a final status value. The vrfy script can be rewritten to set a testable status value by changing the last line from:

expect "250" {puts "GOOD"} 
       "550" {puts "BAD"}

to:

expect "250" {exit 0} 
       "550" {exit 1}

Now it can be used in a shell script without producing any output. For example, from a Bourne shell script, you can use the script as:

if vrfy [email protected]; then
  . . . do something . . .
fi

Note that the shell considers an exit value of zero as true. Anything else is considered false. This differs from most languages (e.g., Tcl, C) where anything but zero is true.

I can now go back to some earlier scripts and modify them not only to be non-interactive but to suppress all output. Here is a modified version of the ping script from Chapter 4 (p. 97) which only waits two seconds to complete the ping.

#!/usr/local/bin/expect --
log_user 0
spawn ping $host
set timeout 2
expect "alive" {exit 0} timeout {exit 1}

Whether or not the ping succeeds, the script prints nothing. The final command sets the status value though, so that the script can be used easily from shell scripts.

Remember the firstline script from Chapter 6 (p. 134)? It ran an arbitrary program, stopping after matching the first line of output. As written, however, the script had the drawback that if input arrived quickly enough, several lines could appear in the output.

You can fix this script by using log_user and handling the output explicitly. Here is a new version that does just that.

#!/usr/local/bin/expect --
log_user 0
eval spawn $argv
set timeout −1
expect -re "([^
]*)
"
puts "$expect_out(1,string)"

Suppose you accidentally type a command that requires root access, but are not root at the time. If it is just one command, you can type "su root !!“, but more commonly you need to enter several more commands that need root access. su provides no way to pass the old command in to the new root shell and then remain in the new root shell.

The usual solution is to invoke su, type the password, and then retype the command. If you have windows, you can start su and then copy and paste the command from one window to another. Either way, it is a bit of a hassle. The problem is that su provides no mechanism for going back in the history and bringing it to the new environment. If it did, you would not need to retype or copy and paste the old command—su would automatically know it.

Here is a script that address this problem. It starts su, gives it the command supplied as the script argument, and then passes control to the user. For simplicity, the password is taken from the command line. (In Chapter 8 (p. 197), I will show how to provide it in a much more secure way.) This version is called su2.

#!/usr/local/bin/expect --

set timeout −1
log_user 0
spawn su
expect "Password:"         ;# discard su's password prompt
send "[lindex $argv 0]
"  ;# send password to su
expect "
"
log_user 1
expect "Sorry" exit "# "
send "[lrange $argv 1 end]
"
interact          ;# let user type more cmds to root shell

The script temporarily suppresses the output from the su command when the password is prompted for and consumed. Here is how it appears when I use it. First I set up the scenario by typing a command that is rejected:

% touch /etc/passwd
touch: cannot touch /etc/passwd: no write permission

Now I call the Expect script with the root password and !! to refer to the previous command. This shell echoes it because it contains a history reference.

57% su2 xxj24k !!
su2 xxj24k touch /etc/passwd
1# touch /etc/passwd
2#

The script then kicks in and starts su. With "log_user 0“, the script responds to the password prompt without displaying it, and then feeds the command to the root shell. Finally, the script passes control to the keyboard via the interact command, leaving me in the root shell.

The result is that I have typed no more than necessary. In fact, with a shell function, you can even have your shell provide the history reference for you. But passing an argument such as !! is a good way. This allows fast references to other commands in the history. And, if your shell supports command-line editing, you can back up to the previous command and just insert the "su2" in front of it.

In this example, "log_user 1" came after "log_user 0“, but like "exp_internal 1" and "exp_internal 0“, either "log_user 1" or "log_user 0" may be repeated without the other. For example, using "log_user 0" twice in a row is legitimate. It is not necessary to keep track of what has happened in the past.

It is possible to save in a file all the output that Expect produces. This includes not only the output from a spawned process, but anything that Expect itself generates such as diagnostics. Conceptually, this is akin to piping Expect’s standard output and standard error through the tee program. However, tee is fairly inflexible in that its piping cannot be modified once Expect has started.

Expect has a programmatic means to start and stop recording (or logging). Given a file name argument, the log_file command opens the file and begins recording to it. If a log file is already open, the old file is closed first. Using the -open or -leaveopen flag, the log_file command can also record to a file opened by the open command. The use of these flags are identical to their use in the spawn command (Chapter 13 (p. 285)) so I will not mention them further here.

Recording is done by appending to the file, so if anything has previously been stored in the file, it remains. To start over, use the -noappend flag (or simply remove the file first).

For example, the UNIX script command can be emulated with the following commands:

spawn $env(SHELL)
log_file -noappend typescript
interact

First a shell is started. Notice how the user’s desired shell is determined by getting it from the environment where it is stored in the variable SHELL. This is much more polite than simply starting up, say, /bin/csh. The log_file command then opens the file typescript. The -noappend flag forces the log to start out empty. Finally, interact passes control to the user. Everything the programs sends to the user is recorded. As before, user keystrokes are not recorded directly. The keystrokes are only recorded if they are echoed. Thus, if a user types a password, the password is not recorded.

In Chapter 15 (p. 330), I will show a modified version of this script that allows a user to turn recording on and off as desired.

log_file is very useful for debugging Expect scripts. It can be used to transparently record everything the user sees. Then, if a user reports a problem with the script, you can examine the log file to see exactly what the user was doing. If parity is being stripped, characters are saved to the log without parity. Nulls are recorded to the log even if they are being removed for the purposes of pattern matching.

You can save space by turning off logging when it is not necessary. This is accomplished by calling log_file with no arguments. For example, the following fragment starts recording, does some I/O, stops recording, does some more I/O, and then starts recording again.

expect . . . ; send . . .
log_file telnetlog
expect . . . ; send . . .
log_file
expect . . . ; send . . .
log_file telnetlog
expect . . . ; send . . .

By default, log_file records only what the user sees. If the log_user command has been invoked to suppress output from a spawned program, the suppressed output is not recorded by log_file since the user is not seeing it either. The log_file can record the suppressed output by using the -a flag (for "all output”).

log_file -a log

As before, this logging can be disabled by issuing log_file with no arguments. To return to logging just what the user sees, invoke log_file without the -a.

log_file -a log
expect . . . ; send . . .
log_file log

The log_file command should not be viewed as the only way to log sessions. It is useful for many purposes, however it does not provide support for very sophisticated types of logging. Many of these can be achieved not with the log_file command but with a little straightforward coding. For example, I will describe how to log multiple process to separate files in Chapter 18 (p. 403) without using the log_file command.

Another deficiency of the log_file command is that it does not save the output of Tcl commands. Arbitrary Tcl commands provide their own output mechanism. Fortunately, this is not a real problem because there is only one Tcl command that ordinarily sends character to the standard output: puts. Expect provides a substitute for puts: send_user. For example, to send the string "hello world " to the standard output:

send_user "hello world
"

send_user is a little different than puts in that send_user does not append a newline at the end of every string. send_user also supports some other behaviors that will be covered in Chapter 8 (p. 181) and Chapter 12 (p. 267). Most importantly though, send_user allows logging of output through log_file. So if your other choices are equal, use send_user instead of puts.

The send_log command is similar to the send command; however, send_log writes to the log without writing to the standard output. It also writes to any file opened by exp_internal. The log_user command has no affect on send_log.

send_log "Beginning transaction at [exec date]
"

Both the exp_internal and log_file commands accept filename arguments that begin with a tilde (”~“). The tilde is interpreted as meaning “home directory” exactly the way it is defined by the C-shell. For example:

exp_internal -f ~fred/debuglog 0

This command saves diagnostic information to the file debuglog in fred’s home directory.

No other interpretation is given to the file name. If you include a wildcard such as a "*“, the file will be created with that name, exactly as you have specified. If you want wildcards expanded, use the glob command.

The log and diagnostic states can be obtained by calling the original commands with the -info flag. The previous parameters are returned. This is commonly used to establish a temporary state.

For example, a subroutine that must be sure that output to the user is disabled should save and restore the state of log_user.

proc sub {} {
    set state [log_user -info]      ;# save old state
    log_user 0                      ;# set new state
    # your code goes here
    eval log_user $state            ;# restore old state
}

Notice the final call to restore the old state. It uses eval in order to support the possibility of a multi-element state. The list of elements will be split in such a way that the command sees them as separate arguments.

The log_user command is not currently defined to take multiple parameters; however, future expansion is likely so it is a good idea to handle it this way. The log_file and exp_internal commands take multiple arguments already.