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

["Liu, Yong" <yong.liu@intel.com>]

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@arm.com [mailto:Phil.Yang@arm.com]
> Sent: Wednesday, May 16, 2018 1:23 PM
> To: Liu, Yong <yong.liu@intel.com>; dts@dpdk.org
> Cc: nd <nd@arm.com>
> Subject: RE: [PATCH 1/2] framework/qemu_kvm: fix vm control session
> failure
> 
> Hi Marvin,
> 
> The DUT had installed lsof.
> 
> =============
> phil@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@intel.com>
> > Sent: Wednesday, May 16, 2018 1:01 PM
> > 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
> >
> > 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@arm.com [mailto:Phil.Yang@arm.com]
> > > Sent: Wednesday, May 16, 2018 11:56 AM
> > > To: Liu, Yong <yong.liu@intel.com>; dts@dpdk.org
> > > Cc: nd <nd@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@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