[4/4] dts: log stderr with failed remote commands

  Add the executed command stderr to RemoteCommandExecutionError. So that
it is logged as an error, instead of just as debug.

Reviewed-by: Paul Szczepanek <paul.szczepanek@arm.com>
Signed-off-by: Luca Vizzarro <luca.vizzarro@arm.com>
---
 dts/framework/exception.py                     | 10 +++++++---
 dts/framework/remote_session/remote_session.py |  2 +-
 2 files changed, 8 insertions(+), 4 deletions(-)
  

On Mon, Jan 22, 2024 at 7:26 PM Luca Vizzarro <luca.vizzarro@arm.com> wrote:
>
> Add the executed command stderr to RemoteCommandExecutionError. So that
> it is logged as an error, instead of just as debug.

Here's I'd add logged additionally as an error, as this sounds as if
we're changing debug to error.

>
> Reviewed-by: Paul Szczepanek <paul.szczepanek@arm.com>
> Signed-off-by: Luca Vizzarro <luca.vizzarro@arm.com>
> ---
>  dts/framework/exception.py                     | 10 +++++++---
>  dts/framework/remote_session/remote_session.py |  2 +-
>  2 files changed, 8 insertions(+), 4 deletions(-)
>
> diff --git a/dts/framework/exception.py b/dts/framework/exception.py
> index 658eee2c38..9fc3fa096a 100644
> --- a/dts/framework/exception.py
> +++ b/dts/framework/exception.py
> @@ -130,20 +130,24 @@ class RemoteCommandExecutionError(DTSError):
>      #: The executed command.
>      command: str
>      _command_return_code: int
> +    _command_stderr: str
>

I'd change the order here (and all other places) so that stderr is
before the return code.

> -    def __init__(self, command: str, command_return_code: int):
> +    def __init__(self, command: str, command_return_code: int, command_stderr: str):
>          """Define the meaning of the first two arguments.
>
>          Args:
>              command: The executed command.
>              command_return_code: The return code of the executed command.
> +            command_stderr: The stderr of the executed command.
>          """
>          self.command = command
>          self._command_return_code = command_return_code
> +        self._command_stderr = command_stderr
>
>      def __str__(self) -> str:
> -        """Include both the command and return code in the string representation."""
> -        return f"Command {self.command} returned a non-zero exit code: {self._command_return_code}"
> +        """Include the command, its return code and stderr in the string representation."""
> +        return (f"Command '{self.command}' returned a non-zero exit code: "
> +                f"{self._command_return_code}\n{self._command_stderr}")

We should mention that the last string is the stderr output. Maybe we
just add 'Stderr:' before {self._command_stderr}. And maybe we should
put quotes around {self._command_stderr}.

>
>
>  class RemoteDirectoryExistsError(DTSError):
> diff --git a/dts/framework/remote_session/remote_session.py b/dts/framework/remote_session/remote_session.py
> index 2059f9a981..345439f2de 100644
> --- a/dts/framework/remote_session/remote_session.py
> +++ b/dts/framework/remote_session/remote_session.py
> @@ -157,7 +157,7 @@ def send_command(
>              )
>              self._logger.debug(f"stdout: '{result.stdout}'")
>              self._logger.debug(f"stderr: '{result.stderr}'")
> -            raise RemoteCommandExecutionError(command, result.return_code)
> +            raise RemoteCommandExecutionError(command, result.return_code, result.stderr)
>          self._logger.debug(f"Received from '{command}':\n{result}")
>          self.history.append(result)
>          return result
> --
> 2.34.1
>
  

On 29/01/2024 13:10, Juraj Linkeš wrote:
> Here's I'd add logged additionally as an error, as this sounds as if
> we're changing debug to error

That is also a way of doing this, but an error is an error. If we wanted 
to log the same thing in debug and error, then when we go read the debug 
we get duplicates... making it less readable. What do you say?

> I'd change the order here (and all other places) so that stderr is
> before the return code.
Ack.

> We should mention that the last string is the stderr output. Maybe we
> just add 'Stderr:' before {self._command_stderr}. And maybe we should
> put quotes around {self._command_stderr}.

Since you mentioned "quotes", I'd think that it'd be even better to 
indent it as if it's a quote. With logs as busy as the ones DTS prints, 
adding some quotes may not change much as it's all already very crowded. 
Can prefix with 'Stderr: ' though.
  

On Fri, Feb 23, 2024 at 8:19 PM Luca Vizzarro <Luca.Vizzarro@arm.com> wrote:
>
> On 29/01/2024 13:10, Juraj Linkeš wrote:
> > Here's I'd add logged additionally as an error, as this sounds as if
> > we're changing debug to error
>
> That is also a way of doing this, but an error is an error. If we wanted
> to log the same thing in debug and error, then when we go read the debug
> we get duplicates... making it less readable. What do you say?
>

I meant let's change the commit message wording to better reflect what
the patch does - it adds stderr to the exception, not doing something
instead of logging it as debug (it could be understood this way). But
it doesn't really matter much. Maybe a better wording of the second
sentence would be "So that, instead of logging it just as debug, it is
also stored in an error, ."

> > I'd change the order here (and all other places) so that stderr is
> > before the return code.
> Ack.
>
> > We should mention that the last string is the stderr output. Maybe we
> > just add 'Stderr:' before {self._command_stderr}. And maybe we should
> > put quotes around {self._command_stderr}.
>
> Since you mentioned "quotes", I'd think that it'd be even better to
> indent it as if it's a quote. With logs as busy as the ones DTS prints,
> adding some quotes may not change much as it's all already very crowded.
> Can prefix with 'Stderr: ' though.

The prefix is essential so that we know what the output actually is.
Indenting it sounds great.