I have a bit of a code that uses pexpect to control a process and some prints in the code. The main goal (in this question) is to have the pexpect output and prints logged into some log file. The problem I ran into is that the pexpect lines (data sent and received) is mingled with the prints with no apparent logic. I was expecting that the print strings and pexpect outputs will be logged in the order they were issued.
Sample code is the following:
#!/usr/bin/env python
import pexpect
import time, sys, os
###############################################################################
# Subclass of file object to avoid recording extensive whitespace characters
class CleanFile(file):
def write (self, text):
# Remove the whitespaces
out_text = ''
# process the backspace properly
bline = ''
for c in text:
if (ord(c) == 0x8):
if (len(bline) == 0):
# Move the file pointer.
file.seek(self, -1, os.SEEK_CUR);
else:
bline = bline[:-1]
else:
bline += c
# remove whitespaces from inside a line
out_text += ''.join(c for c in bline if (ord(c) >= 32 or ord(c) == 10));
file.write(self, out_text);
###############################################################################
def main():
fout = CleanFile ("options.log_file.log", 'w')
sys.stdout = os.fdopen (sys.stdout.fileno(), 'w', 0)
os.dup2 (fout.fileno(), sys.stdout.fileno());
p = pexpect.spawn ('tclsh')
p.logfile = fout
print "Got into tclsh."
p.sendline('ls');
p.expect (['%',pexpect.EOF])
p.sendline('info tclversion');
p.expect (['%',pexpect.EOF])
print "Got the version\n"
p.sendline('info commands %');
p.expect (['%',pexpect.EOF])
p.sendline('exit');
print 'Ended session'
###############################################################################
if __name__ == "__main__":
main()
This is the output log file contents:
Got into tclsh.
ls
% lsinfo tclversion
log options.log_file.log pexpect_test.py runtests.py runtests_steinway.py
% info tclversionGot the version
info commands %
8.4
% info commands %exit
Ended session
Is there any way to make the pexpect and print outputs sequential?
Update: Based on the pexpect manual page: "Please note, however, that buffering can affect this behavior, since
input arrives in unpredictable chunks". So it may potentially affect the logging.
Answer
If you can wait until the script ends for the results, don't set a log file for pexpect commands, save results of the commands to variables, and print everything in the end.
Note also that you are missing the output of the info commands command. This can be fixed by adding one expect() for waiting the tclsh interpreter to start and removing the '%' from the end of the command. I assumed that was a typo.
Modify main function to be:
def main():
fout = CleanFile ("options.log_file.log", 'w')
sys.stdout = os.fdopen (sys.stdout.fileno(), 'w', 0)
os.dup2 (fout.fileno(), sys.stdout.fileno());
p = pexpect.spawn ('tclsh')
p.expect (['%',pexpect.EOF])
p.sendline('ls');
p.expect (['%',pexpect.EOF])
ls = p.before
p.sendline('info tclversion');
p.expect (['%',pexpect.EOF])
tclversion = p.before
p.sendline('info commands');
p.expect (['%',pexpect.EOF])
commands = p.before
p.sendline('exit');
p.close()
print "Got into tclsh."
print ls
print tclversion
print "Got the version\n"
print commands
print "Ended session"
The output is then:
Got into tclsh.
ls
options.log_file.log pexpect_test.py
info tclversion
8.5
Got the version
info commands
tell socket subst open eof pwd glob list pid exec auto_load_index time unknown
eval lassign lrange fblocked lsearch auto_import gets case lappend proc break v
ariable llength auto_execok return linsert error catch clock info split array i
f fconfigure concat join lreplace source fcopy global switch auto_qualify updat
e close cd for auto_load file append lreverse format unload read package set bi
nary namespace scan apply trace seek while chan flush after vwait dict continue
uplevel foreach lset rename fileevent regexp lrepeat upvar encoding expr unset
load regsub history interp exit puts incr lindex lsort tclLog string
Ended session