[FIXED] issue about pexpect logfile_read

Issue

use pexpect SSH connections to run cmds on remote server, the command can be executed, but the results displayed on the terminal are not as expected, code like this（At first there was no time.sleep, it was added for debugging）

import logging
import time

from pexpectUtility import Session

logger = logging.getLogger(__name__)


def test_create_and_show():
    cliPrompt = 'dev-r0'
    hostPrompt = 'admin@dev-r0'

    aa = Session()
    aa.connect("admin","password", "10.10.0.10")
    time.sleep(2)
    
    aa.child.sendline("sonic-cli")
    aa.child.expect(cliPrompt, 3)
    tTime = 0
    time.sleep(tTime)

    aa.child.sendline("configure terminal")
    aa.child.expect(cliPrompt, 3)

    time.sleep(tTime)
    aa.child.sendline("end")
    aa.child.expect(cliPrompt, 3)
    time.sleep(tTime)
    aa.child.sendline("exit")
    aa.child.expect(hostPrompt, 3)

    aa.disconnect()

the pexpectUtility.py

import sys
import logging as log


if sys.platform == 'win32':
    import WExpect as pexpect
    spawn_class = pexpect.spawn_windows
else:
    import pexpect
    spawn_class = pexpect.spawn

class MutliIO:
    def __init__(self, *fds):
        self.fds = fds

    def write(self, data):
        for fd in self.fds:
            fd.write(data)

    def flush(self):
        for fd in self.fds:
            fd.flush()


class Session(spawn_class):
    def __init__(self):
        self.child  = None

    def connect(self, username, password, serverIp, protocol='ssh'):
        self.protocol = protocol
        self.username = username
        self.password = password
        self.serverIp = serverIp

        if protocol == 'ssh':
            cmd = "ssh -x -o StrictHostKeyChecking=no -l %s " % self.username
        else:
            cmd = "telnet "

        cmd = cmd + serverIp
        log.info('Connecting to Dut: %s\n' %(cmd))
        expect_list = ['ogin: $', '[P|p]assword:', '\[confirm\] $',
                        '\[confirm yes/no\]:',  '\[yes/no\]:', '\(yes/no\)\?',
                        '\[y/n\]:', '--More--', 'ONIE:/ #',
                        pexpect.TIMEOUT, pexpect.EOF]
                        
        self.child = spawn_class(cmd)
        logfile = open('pexpect.log', 'w')
        self.child.logfile_read = MutliIO(sys.stdout)
        # self.child.logfile_read = MutliIO(sys.stdout, logfile)
        # self.child.logfile_read = MutliIO(logfile)
        try:
            re = self.child.expect(expect_list, 10)
            log.debug("expect pwd: {}".format(re))
        except Exception as err:
            log.error('%s' %err)
            raise

        # login
        try:
            self.child.sendline(self.password)
        except Exception as err:
            raise RuntimeError("login failed!", err)

    def disconnect(self):
        self.child.sendline("exit")
        self.child.expect(pexpect.EOF)
        self.child.close()
        if self.child.logfile_read != None:
            self.child.logfile_read = None

Executed commands are repeated displayed, just like batch input. log is as follows:

admin@dev-r0:~$ sonic-cli
configure terminal
configure terminal
end
exit
dev-r0# configure terminal
dev-r0(config)# end
dev-r0# exit
admin@dev-r0:~$ exit
logout
Connection to 10.10.0.10 closed.

When I set tTime to 5 (each command interval is 5 seconds) the log is as expected，I think this is not a good solution，I also want to know the root cause

admin@dev-r0:~$ sonic-cli
dev-r0# configure terminal
dev-r0(config)# end
dev-r0# exit
admin@dev-r0:~$ exit
logout
Connection to 10.10.0.10 closed.

When I directly use expect to implement the above operation, there is no need to wait for 5 seconds between commands, and the log displayed by the terminal is normal.

why pexpect has this issue? how to solve this？ Thanks in advance

Solution

Referring to the sample code of pexpect on the Internet, I found that the root cause is a code problem: missing a expect() after sendline()

The changes are as follows:

        # login
        try:
            self.child.sendline(self.password)
            HOST_PROMPT = '\$' # remote server prompt
            re = self.child.expect(HOST_PROMPT)
        except Exception as err:
            raise RuntimeError("login failed!", err)

Answered By - Gavin Hunter21