Re: [dts] [PATCH 1/2] framework/qemu_kvm: fix vm control session failure

[Phil Yang <Phil.Yang@arm.com>]

Hi Marvin,

For telnet vm control I've encountered serial connection got no repose after first time login failure. Below is the log. Please check it.
=======================================================
m] Started Load/Save Random Seed.[\x1b[0;32m  OK  \x1b[0m] Started Apply Kernel Variables.[\x1b[0;32m  OK  \x1b[0m] Mounted FUSE Control File System.[\x1b[0;32m  OK  \x1b[0m] Mounted Kernel Configuration File System.[\x1b[0;32m  OK  \x1b[0m] Started Create Static Device Nodes in /dev.         Starting udev Kernel Device Manager...[\x1b[0;32m  OK  \x1b[0m] Reached target Local File Systems (Pre).[\x1b[0;32m  OK  \x1b[0m] Started udev Kernel Device Manager.[\x1b[0;32m  OK  \x1b[0m] Started Dispatch Password Requests to Console Directory Watch.[\x1b[0;32m  OK  \x1b[0m] Reached target Local Encrypted Volumes.[\x1b[0;32m  OK  \x1b[0m] Activated swap /swapfile.[\x1b[0;32m  OK  \x1b[0m] Reached target Swap.[\x1b[0;32m  OK  \x1b[0m] Started Flush Journal to Persistent Storage."
(Pdb) c
[10.169.40.174:vm0] not ready for login
             dut.10.169.40.174: Can't login [vm0] on [10.169.40.174], retry 1 times!!!
             dut.10.169.40.174: lsof -i:7002 | grep telnet | awk '{print $2}'
Exception happened in [lsof -i:7002 | grep telnet | awk '{print $2}'] and output is [lsof -i:7002 | grep telnet | awk '{print $2}'
Command not found]
Traceback (most recent call last):
  File "/root/dpdk-dts/framework/virt_base.py", line 284, in start
    self._start_vm()
  File "/root/dpdk-dts/framework/qemu_kvm.py", line 1269, in _start_vm
    self.__wait_vm_ready()
TimeoutException: TIMEOUT on lsof -i:7002 | grep telnet | awk '{print $2}'
Unhandled expection <class 'exception.TimeoutException'>
            TestVhostPmdXstats: Failure for Set up VM ENV failed
============================================================

So I added a delay to flush the useless output. Which can resolve this issue.
BTW, only telnet connection has this defect. This fix is kind of workaround, but It works.

Thanks,
Phil Yang

> -----Original Message-----
> From: Liu, Yong <yong.liu@intel.com>
> Sent: Wednesday, May 16, 2018 9:38 AM
> To: Phil Yang <Phil.Yang@arm.com>; dts@dpdk.org
> Cc: nd <nd@arm.com>
> Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control session failure
> 
> Thanks, Phil. I'm fine with the changes, just one question about the issue you
> met.
> Qemu module should has taken care of the problem that VM maybe can't login
> for the first time.
> If login action can't be done continuously, I think there may be some kind of
> issue here.
> Could you please check the output of serial session? It may help us to figure out
> the problem.
> 
> Regards,
> Marvin
> 
> > -----Original Message-----
> > From: phil.yang@arm.com [mailto:phil.yang@arm.com]
> > Sent: Tuesday, May 15, 2018 6:06 PM
> > To: dts@dpdk.org
> > Cc: nd@arm.com; phil.yang@arm.com; Liu, Yong <yong.liu@intel.com>
> > Subject: [PATCH 1/2] framework/qemu_kvm: fix vm control session
> > failure
> >
> > For telnet vm control, it will continuously fail to login to vm when
> > it doesn't read login prompt during first time connection. So extend
> > the connection time to get more output each time.
> >
> > For socket vm control, added LOGIN_PROMPT into the login status check
> > for other platform.
> > Keep the connection longer to avoid failure and reconnection.
> >
> > Signed-off-by: Phil Yang <phil.yang@arm.com>
> > ---
> >  framework/qemu_kvm.py | 11 ++++++-----
> >  1 file changed, 6 insertions(+), 5 deletions(-)
> >
> > diff --git a/framework/qemu_kvm.py b/framework/qemu_kvm.py index
> > ec33669..57d16f6 100644
> > --- a/framework/qemu_kvm.py
> > +++ b/framework/qemu_kvm.py
> > @@ -979,7 +979,7 @@ class QEMUKvm(VirtBase):
> >          Connect to serial port and return connected session for usage
> >          if connected failed will return None
> >          """
> > -        shell_reg = r"(\s*)\[(.*)\]# "
> > +        shell_reg = r"(.*)# "
> >          try:
> >              if getattr(self, 'control_session', None) is None:
> >                  self.control_session = self.host_session @@ -987,7
> > +987,7 @@ class QEMUKvm(VirtBase):
> >                  self.control_session.send_command("nc -U %s" %
> > self.serial_path)
> >
> >              # login message not ouput if timeout too small
> > -            out = self.control_session.send_command("",
> > timeout=5).replace('\r', '').replace('\n', '')
> > +            out = self.control_session.send_command("",
> > timeout=15).replace('\r', '').replace('\n', '')
> >
> >              if len(out) == 0:
> >                  raise StartVMFailedException("Can't get output from
> > [%s:%s]" % (self.host_dut.crb['My IP'], self.vm_name)) @@ -1025,7
> > +1025,7 @@ class QEMUKvm(VirtBase):
> >          Connect to serial port and return connected session for usage
> >          if connected failed will return None
> >          """
> > -        shell_reg = r"(\s*)\[(.*)\]# "
> > +        shell_reg = r"(.*)# "
> >          scan_cmd = "lsof -i:%d | grep telnet | awk '{print $2}'" %
> > self.serial_port
> >
> >          try:
> > @@ -1034,9 +1034,10 @@ class QEMUKvm(VirtBase):
> >                  self.control_session = self.host_session
> >
> >                  self.control_session.send_expect("telnet localhost
> > %d" % self.serial_port, "Connected to localhost",
> > timeout=self.OPERATION_TIMEOUT)
> > +                time.sleep(5)
> >
> >              # output will be empty if timeout too small
> > -            out = self.control_session.send_command("",
> > timeout=5).replace('\r', '').replace('\n', '')
> > +            out = self.control_session.send_command("",
> > timeout=10).replace('\r', '').replace('\n', '')
> >
> >              # if no output from serial port, either connection close
> > or system hang
> >              if len(out) == 0:
> > @@ -1058,7 +1059,7 @@ class QEMUKvm(VirtBase):
> >                      return True
> >
> >              # login into Redhat os, not sure can work on all
> > distributions
> > -            if "x86_64 on an x86_64" not in out:
> > +            if ("x86_64 on an x86_64" not in out) and
> > + (self.LOGIN_PROMPT
> > not in out):
> >                  print RED("[%s:%s] not ready for login" %
> > (self.host_dut.crb['My IP'], self.vm_name))
> >                  return False
> >              else:
> > --
> > 2.7.4