arm/lib: Improve FVPRunner shutdown logic

From: Peter Hoyes <Peter.Hoyes@arm.com>

Please can this be applied to master + kirkstone.

We have encountered intermittent hanging during FVP shutdown, so improve
the termination logic by first issuing a terminate(), waiting a bit
then, if necessary, issuing a kill().

Move returncode logic to after the telnet/pexpect cleanup so it
actually runs.

Move pexpect.EOF logic into FVPRunner.stop so that it executes before
closing the pexpect handle.

Issue-Id: SCM-4957
Signed-off-by: Peter Hoyes <Peter.Hoyes@arm.com>
Change-Id: Iebb3c3c89367256b1e116e66ffdb6b742358bce4
---
 meta-arm/lib/fvp/runner.py           | 34 +++++++++++++++++++---------
 meta-arm/lib/oeqa/controllers/fvp.py |  6 -----
 2 files changed, 23 insertions(+), 17 deletions(-)

On Mon, Jul 18, 2022 at 01:15:33PM +0100, Peter Hoyes wrote:
> From: Peter Hoyes <Peter.Hoyes@arm.com>
> 
> Please can this be applied to master + kirkstone.

Applying to both master and kirkstone.

In the future, please add requests like this in the patch after the ---
Otherwise, it will get pulled into the commit message, and I have to
edit it out by hand.  Alternatively, you can send a second email with
"kirkstone" in the subject line after "PATCH" (and my scripts will
automatically pull it in).  Finally, you can just respond to the
initial email with a "and kirkstone too" and I'll do it manually then.

Thanks,
Jon

> 
> We have encountered intermittent hanging during FVP shutdown, so improve
> the termination logic by first issuing a terminate(), waiting a bit
> then, if necessary, issuing a kill().
> 
> Move returncode logic to after the telnet/pexpect cleanup so it
> actually runs.
> 
> Move pexpect.EOF logic into FVPRunner.stop so that it executes before
> closing the pexpect handle.
> 
> Issue-Id: SCM-4957
> Signed-off-by: Peter Hoyes <Peter.Hoyes@arm.com>
> Change-Id: Iebb3c3c89367256b1e116e66ffdb6b742358bce4
> ---
>  meta-arm/lib/fvp/runner.py           | 34 +++++++++++++++++++---------
>  meta-arm/lib/oeqa/controllers/fvp.py |  6 -----
>  2 files changed, 23 insertions(+), 17 deletions(-)
> 
> diff --git a/meta-arm/lib/fvp/runner.py b/meta-arm/lib/fvp/runner.py
> index 3b3fd00..7641cd6 100644
> --- a/meta-arm/lib/fvp/runner.py
> +++ b/meta-arm/lib/fvp/runner.py
> @@ -72,24 +72,36 @@ class FVPRunner:
>  
>      async def stop(self):
>          if self._fvp_process:
> -            self._logger.debug(f"Killing FVP PID {self._fvp_process.pid}")
> +            self._logger.debug(f"Terminating FVP PID {self._fvp_process.pid}")
>              try:
>                  self._fvp_process.terminate()
> +                await asyncio.wait_for(self._fvp_process.wait(), 10.0)
> +            except asyncio.TimeoutError:
> +                self._logger.debug(f"Killing FVP PID {self._fvp_process.pid}")
> +                self._fvp_process.kill()
>              except ProcessLookupError:
>                  pass
>  
> -            if await self._fvp_process.wait() != 0:
> -                self._logger.info(f"FVP quit with code {self._fvp_process.returncode}")
> -                return self._fvp_process.returncode
> -            else:
> -                return 0
> -
>          for telnet in self._telnets:
> -            await telnet.terminate()
> -            await telnet.wait()
> +            try:
> +                telnet.terminate()
> +                await asyncio.wait_for(telnet.wait(), 10.0)
> +            except asyncio.TimeoutError:
> +                telnet.kill()
> +            except ProcessLookupError:
> +                pass
> +
> +        for console in self._pexpects:
> +            import pexpect
> +            # Ensure pexpect logs all remaining output to the logfile
> +            console.expect(pexpect.EOF, timeout=5.0)
> +            console.close()
>  
> -        for pexpect in self._pexpects:
> -            pexpect.close()
> +        if self._fvp_process and self._fvp_process.returncode:
> +            self._logger.info(f"FVP quit with code {self._fvp_process.returncode}")
> +            return self._fvp_process.returncode
> +        else:
> +            return 0
>  
>      async def run(self, until=None):
>          if until and until():
> diff --git a/meta-arm/lib/oeqa/controllers/fvp.py b/meta-arm/lib/oeqa/controllers/fvp.py
> index 30b6296..c8dcf29 100644
> --- a/meta-arm/lib/oeqa/controllers/fvp.py
> +++ b/meta-arm/lib/oeqa/controllers/fvp.py
> @@ -127,12 +127,6 @@ class OEFVPSerialTarget(OEFVPSSHTarget):
>                  default_test_file = f"{name}_log{self.test_log_suffix}"
>                  os.symlink(default_test_file, self.bootlog)
>  
> -    async def _after_stop(self):
> -        # Ensure pexpect logs all remaining output to the logfile
> -        for terminal in self.terminals.values():
> -            terminal.expect(pexpect.EOF, timeout=5)
> -            terminal.close()
> -
>      def _get_terminal(self, name):
>          return self.terminals[name]
>  
> -- 
> 2.25.1
> 
>

Thanks as ever.

And noted - I'll send a second email in future.

Peter

On Mon, 18 Jul 2022 13:15:33 +0100, Peter Hoyes wrote:
> Please can this be applied to master + kirkstone.
> 
> We have encountered intermittent hanging during FVP shutdown, so improve
> the termination logic by first issuing a terminate(), waiting a bit
> then, if necessary, issuing a kill().
> 
> Move returncode logic to after the telnet/pexpect cleanup so it
> actually runs.
> 
> [...]

Applied, thanks!

[1/1] arm/lib: Improve FVPRunner shutdown logic
      commit: 78fce73c3803aba82149a3a03fde1b708f5424fa

Best regards,