Re: [PATCH] testsuite: Improve SSH ping

[Henning Schild <henning.schild@siemens.com>]

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

I find all that code kind of hard to read. With the multiple
indirections to find the command that actually gets executed in the
end. A quick look makes one think it is "/bin/true".

and for a counting loop python has
"for i in range(3)"

The idea to wait a bit longer is good, and if that works it can be
merged. But the code could likely by written in a way that it would be
easier to read and maintain.

Henning

> +                # 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
>  
>          if rc != 0:
>              self.log.error('SSH server is not ready')