Re: [PATCH] testsuite: Improve SSH ping

[Uladzimir Bely <ubely@ilbers.de>]

In mail from Friday, 17 March 2023 11:53:58 +03 user Henning Schild wrote:
> Am Fri, 17 Mar 2023 05:11:30 +0100
> 
> schrieb Uladzimir Bely <ubely@ilbers.de>:
> > When qemu machine boots, it may happen that consecutive SSH connection
> > fails right after the previous good one. So, we get a situation when
> > the command/script fails after we consider SSH is ready.
> > 
> > This patch improves detection of SSH server ready status by making at
> > least three good consecutive SSH pings.
> > 
> > Example of debug output that shows the case:
> > 
> > ```
> > 
> > | Waiting for SSH server ready...
> > | SSH ping result: 255, left: 300s # <== machine is booting
> > | SSH ping result: 255, left: 294s
> > | SSH ping result: 255, left: 288s
> > | SSH ping result: 255, left: 282s
> > | SSH ping result: 255, left: 276s
> > | SSH ping result: 255, left: 270s
> > | SSH ping result: 255, left: 264s
> > | SSH ping result: 255, left: 258s
> > | SSH ping result: 0, left: 253s   # <== SSH server is up...
> > | SSH ping result: 0, left: 251s
> > | SSH ping result: 255, left: 250s # <== but one ping failed again
> > | SSH ping result: 0, left: 248s
> > | SSH ping result: 0, left: 245s
> > | SSH ping result: 0, left: 243s
> > | SSH server is ready
> > | `lsmod | grep example_module` returned 0
> > 
> > ```
> > 
> > Signed-off-by: Uladzimir Bely <ubely@ilbers.de>
> > ---
> > 
> >  testsuite/cibuilder.py | 12 ++++++++++--
> >  1 file changed, 10 insertions(+), 2 deletions(-)
> > 
> > diff --git a/testsuite/cibuilder.py b/testsuite/cibuilder.py
> > index 9e84c3a3..4e568b8e 100755
> > --- a/testsuite/cibuilder.py
> > +++ b/testsuite/cibuilder.py
> > 
> > @@ -257,17 +257,25 @@ class CIBuilder(Test):
> >          self.log.debug('Waiting for SSH server ready...')
> >          
> >          rc = None
> > 
> > +        goodcnt = 0
> > 
> >          while time.time() < timeout:
> >              if proc.poll() is not None:
> >                  self.log.error('Machine is not running')
> >                  return rc
> >              
> >              rc = self.exec_cmd('/bin/true', cmd_prefix)
> > 
> > +            time_left = timeout - time.time()
> > +            self.log.debug('SSH ping result: %d, left: %.fs' % (rc,
> > time_left)) time.sleep(1)
> > 
> >              if rc == 0:
> > -                self.log.debug('SSH server is ready')
> > -                break
> > +                goodcnt += 1
> > +                # Let 3 good SSH pings to make sure SSH connection
> > is stable
> > +                if goodcnt >= 3:
> > +                    self.log.debug('SSH server is ready')
> > +                    break
> > +            else:
> > +                goodcnt = 0
> 
> This looks like an endless loop should ssh never come up. Not sure what
> would break that loop. In the worst case a test-timeout and everything
> being stuck because we might not execute these things in parallel.
> 

In case ssh never come up, we will exit after the timeout (default value 
600sec), goodcnt will always be 0 in this case.

Using something more readable like "for i in range(3)" you've suggested in the 
previous comment won't work because we need to reset the counter and start 
again in case one of pings goes wrong. E.g, if second ping fails, we need 
`goodcnt` changes like 0-0-0-1-0-1-2-3. With "range" function it will act like 
0-0-0-1-0-3.

But you are right, code like "while time.time() < timeout and goodcnt < 3" 
might be a bit more readable. I'll check it.

> Henning
> 
> >          if rc != 0:
> >              self.log.error('SSH server is not ready')