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

[Phil Yang]

Thanks Marvin. You are right, the delay is unnecessary.

I'll rework the patch.

Thanks,
Phil Yang

> -----Original Message-----
> From: Liu, Yong <yong.liu at intel.com>
> Sent: Wednesday, May 16, 2018 2:37 PM
> To: Phil Yang <Phil.Yang at arm.com>; dts at dpdk.org
> Cc: nd <nd at arm.com>
> Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control session failure
> 
> Phil,
> As I known, this command will only send to self.host_dut which should not be
> possible to occur below error.
> Is your dut running some other processes?
> 
> [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]
> 
> 
> 
> Thanks,
> Marvin
> 
> > -----Original Message-----
> > From: Phil.Yang at arm.com [mailto:Phil.Yang at arm.com]
> > Sent: Wednesday, May 16, 2018 1:23 PM
> > To: Liu, Yong <yong.liu at intel.com>; dts at dpdk.org
> > Cc: nd <nd at arm.com>
> > Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control session
> > failure
> >
> > Hi Marvin,
> >
> > The DUT had installed lsof.
> >
> > =============
> > phil at net-arm-c2400_01:~$ sudo lsof -i:7000 | grep telnet
> > telnet    24489 root    3u  IPv4 256487      0t0  TCP localhost:58776-
> > >localhost:afs3-fileserver (ESTABLISHED)
> > =============
> >
> > Thanks,
> > Phil Yang
> >
> > > -----Original Message-----
> > > From: Liu, Yong <yong.liu at intel.com>
> > > Sent: Wednesday, May 16, 2018 1:01 PM
> > > To: Phil Yang <Phil.Yang at arm.com>; dts at dpdk.org
> > > Cc: nd <nd at arm.com>
> > > Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control session
> > failure
> > >
> > > Hi Phil,
> > > From the error log, issue was caused by lsof command not installed.
> > > Qemu module will check whether connection has been established by this
> tool.
> > > Could you please install it and try again? If that fix the issue, I
> > think only shell
> > > regression need to be changed.
> > >
> > > Thanks,
> > > Marvin
> > >
> > > > -----Original Message-----
> > > > From: Phil.Yang at arm.com [mailto:Phil.Yang at arm.com]
> > > > Sent: Wednesday, May 16, 2018 11:56 AM
> > > > To: Liu, Yong <yong.liu at intel.com>; dts at dpdk.org
> > > > Cc: nd <nd at arm.com>
> > > > Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control
> > > > session failure
> > > >
> > > > 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 at intel.com>
> > > > > Sent: Wednesday, May 16, 2018 9:38 AM
> > > > > To: Phil Yang <Phil.Yang at arm.com>; dts at dpdk.org
> > > > > Cc: nd <nd at 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 at arm.com [mailto:phil.yang at arm.com]
> > > > > > Sent: Tuesday, May 15, 2018 6:06 PM
> > > > > > To: dts at dpdk.org
> > > > > > Cc: nd at arm.com; phil.yang at arm.com; Liu, Yong
> > > > > > <yong.liu at 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 at 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