[PATCH v1 0/2] Improve interactive shell output gathering

[PATCH v1 0/2] Improve interactive shell output gathering

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

When the interactive shell was originally added, the gathering of output
was implented in a way that was trying to be flexible enough to gather
output until a given string was found anywhere in the output. It has
been found more recently that this greater flexibility provides less
guarantees when writing tools that implement the shell and ultimately
can lead to unexpected behaviour. This is especially true when sending
multi-line commands into the shell which is desirable in some cases.

To account for this, the prompt will strictly be expected at the end of
a line from the output. There were also some quality of life changes
made to this system such as better wrapping of errors to privde some
more useful output.

Jeremy Spewock (2):
  dts: Improve output gathering in interactive shells
  dts: Add missing docstring from XML-RPC server

 dts/framework/exception.py                    |  7 +++
 .../remote_session/interactive_shell.py       | 26 +++++++----
 .../testbed_model/traffic_generator/scapy.py  | 46 ++++++++++++++++++-
 3 files changed, 70 insertions(+), 9 deletions(-)

-- 
2.43.2

[PATCH v1 1/2] dts: Improve output gathering in interactive shells

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

The current implementation of consuming output from interactive shells
relies on being able to find an expected prompt somewhere within the
output buffer after sending the command. This is useful in situations
where the prompt does not appear in the output itself, but in some
practical cases (such as the starting of an XML-RPC server for scapy)
the prompt exists in one of the commands sent to the shell and this can
cause the command to exit early and creates a race condition between the
server starting and the first command being sent to the server.

This patch addresses this problem by searching for a line that strictly
ends with the provided prompt, rather than one that simply contains it,
so that the detection that a command is finished is more consistent. It
also adds a catch to detect when a command times out before finding the
prompt so that the exception can be wrapped into a more explicit one and
display the output that it did manage to gather before timing out.

Bugzilla ID: 1359
Fixes: 88489c0501af ("dts: add smoke tests")

Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
---
 dts/framework/exception.py                    |  7 +++++
 .../remote_session/interactive_shell.py       | 26 +++++++++++++------
 2 files changed, 25 insertions(+), 8 deletions(-)

diff --git a/dts/framework/exception.py b/dts/framework/exception.py
index 658eee2c38..cce1e0231a 100644
--- a/dts/framework/exception.py
+++ b/dts/framework/exception.py
@@ -146,6 +146,13 @@ def __str__(self) -> str:
         return f"Command {self.command} returned a non-zero exit code: {self._command_return_code}"
 
 
+class InteractiveCommandExecutionError(DTSError):
+    """An unsuccessful execution of a remote command in an interactive environment."""
+
+    #:
+    severity: ClassVar[ErrorSeverity] = ErrorSeverity.REMOTE_CMD_EXEC_ERR
+
+
 class RemoteDirectoryExistsError(DTSError):
     """A directory that exists on a remote node."""
 
diff --git a/dts/framework/remote_session/interactive_shell.py b/dts/framework/remote_session/interactive_shell.py
index 5cfe202e15..2bcfdcb3c7 100644
--- a/dts/framework/remote_session/interactive_shell.py
+++ b/dts/framework/remote_session/interactive_shell.py
@@ -20,6 +20,7 @@
 
 from paramiko import Channel, SSHClient, channel  # type: ignore[import]
 
+from framework.exception import InteractiveCommandExecutionError
 from framework.logger import DTSLogger
 from framework.settings import SETTINGS
 
@@ -124,6 +125,10 @@ def send_command(self, command: str, prompt: str | None = None) -> str:
 
         Returns:
             All output in the buffer before expected string.
+
+        Raises:
+            InteractiveCommandExecutionError: If command was sent but prompt could not be found in
+                the output.
         """
         self._logger.info(f"Sending: '{command}'")
         if prompt is None:
@@ -131,14 +136,19 @@ def send_command(self, command: str, prompt: str | None = None) -> str:
         self._stdin.write(f"{command}{self._command_extra_chars}\n")
         self._stdin.flush()
         out: str = ""
-        for line in self._stdout:
-            out += line
-            if prompt in line and not line.rstrip().endswith(
-                command.rstrip()
-            ):  # ignore line that sent command
-                break
-        self._logger.debug(f"Got output: {out}")
-        return out
+        try:
+            for line in self._stdout:
+                out += line
+                if line.rstrip().endswith(prompt):
+                    break
+        except TimeoutError:
+            raise InteractiveCommandExecutionError(
+                f"Failed to find the prompt ({prompt}) at the end of a line in the output from the"
+                f" command ({command}). Got:\n{out}"
+            )
+        else:
+            self._logger.debug(f"Got output: {out}")
+            return out
 
     def close(self) -> None:
         """Properly free all resources."""
-- 
2.43.2

[PATCH v1 2/2] dts: Add missing docstring from XML-RPC server

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

When this XML-RPC server implementation was added, the docstring had to
be shortened in order to reduce the chances of this race condition being
encountered. Now that this race condition issue is resolved, the full
docstring can be restored.

Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
---
 .../testbed_model/traffic_generator/scapy.py  | 46 ++++++++++++++++++-
 1 file changed, 45 insertions(+), 1 deletion(-)

diff --git a/dts/framework/testbed_model/traffic_generator/scapy.py b/dts/framework/testbed_model/traffic_generator/scapy.py
index 5b60f66237..1b46e613a4 100644
--- a/dts/framework/testbed_model/traffic_generator/scapy.py
+++ b/dts/framework/testbed_model/traffic_generator/scapy.py
@@ -125,9 +125,53 @@ def scapy_send_packets(xmlrpc_packets: list[xmlrpc.client.Binary], send_iface: s
 
 
 class QuittableXMLRPCServer(SimpleXMLRPCServer):
-    """Basic XML-RPC server.
+    r"""Basic XML-RPC server.
 
     The server may be augmented by functions serializable by the :mod:`marshal` module.
+
+    Example:
+        ::
+
+            def hello_world():
+                # to be sent to the XML-RPC server
+                print("Hello World!")
+
+            # start the XML-RPC server on the remote node
+            # the example assumes you're already connect to a tg_node
+            # this is done by starting a Python shell on the remote node
+            from framework.remote_session import PythonShell
+            session = tg_node.create_interactive_shell(PythonShell, timeout=5, privileged=True)
+
+            # then importing the modules needed to run the server
+            # and the modules for any functions later added to the server
+            session.send_command("import xmlrpc")
+            session.send_command("from xmlrpc.server import SimpleXMLRPCServer")
+
+            # sending the source code of this class to the Python shell
+            from xmlrpc.server import SimpleXMLRPCServer
+            src = inspect.getsource(QuittableXMLRPCServer)
+            src = "\n".join([l for l in src.splitlines() if not l.isspace() and l != ""])
+            spacing = "\n" * 4
+            session.send_command(spacing + src + spacing)
+
+            # then starting the server with:
+            command = "s = QuittableXMLRPCServer(('0.0.0.0', {listen_port}));s.serve_forever()"
+            session.send_command(command, "XMLRPC OK")
+
+            # now the server is running on the remote node and we can add functions to it
+            # first connect to the server from the execution node
+            import xmlrpc.client
+            server_url = f"http://{tg_node.config.hostname}:8000"
+            rpc_server_proxy = xmlrpc.client.ServerProxy(server_url)
+
+            # get the function bytes to send
+            import marshal
+            function_bytes = marshal.dumps(hello_world.__code__)
+            rpc_server_proxy.add_rpc_function(hello_world.__name__, function_bytes)
+
+            # now we can execute the function on the server
+            xmlrpc_binary_recv: xmlrpc.client.Binary = rpc_server_proxy.hello_world()
+            print(str(xmlrpc_binary_recv))
     """
 
     def __init__(self, *args, **kwargs):
-- 
2.43.2

Re: [PATCH v1 1/2] dts: Improve output gathering in interactive shells

[Juraj Linkeš]

On Tue, Mar 12, 2024 at 6:26 PM <jspewock@iol.unh.edu> wrote:
>
> From: Jeremy Spewock <jspewock@iol.unh.edu>
>
> The current implementation of consuming output from interactive shells
> relies on being able to find an expected prompt somewhere within the
> output buffer after sending the command. This is useful in situations
> where the prompt does not appear in the output itself, but in some
> practical cases (such as the starting of an XML-RPC server for scapy)
> the prompt exists in one of the commands sent to the shell and this can
> cause the command to exit early and creates a race condition between the
> server starting and the first command being sent to the server.
>
> This patch addresses this problem by searching for a line that strictly
> ends with the provided prompt, rather than one that simply contains it,
> so that the detection that a command is finished is more consistent. It
> also adds a catch to detect when a command times out before finding the
> prompt so that the exception can be wrapped into a more explicit one and
> display the output that it did manage to gather before timing out.
>

This could still cause problems if the prompt appears at the end of a
line in the output. Maybe we don't need to worry about that until we
actually hit that problem. In any case, I'd like to test this, so
please rebase the patch. :-)

> Bugzilla ID: 1359
> Fixes: 88489c0501af ("dts: add smoke tests")
>
> Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
> ---
>  dts/framework/exception.py                    |  7 +++++
>  .../remote_session/interactive_shell.py       | 26 +++++++++++++------
>  2 files changed, 25 insertions(+), 8 deletions(-)
>
> diff --git a/dts/framework/exception.py b/dts/framework/exception.py
> index 658eee2c38..cce1e0231a 100644
> --- a/dts/framework/exception.py
> +++ b/dts/framework/exception.py
> @@ -146,6 +146,13 @@ def __str__(self) -> str:
>          return f"Command {self.command} returned a non-zero exit code: {self._command_return_code}"
>
>
> +class InteractiveCommandExecutionError(DTSError):
> +    """An unsuccessful execution of a remote command in an interactive environment."""
> +
> +    #:
> +    severity: ClassVar[ErrorSeverity] = ErrorSeverity.REMOTE_CMD_EXEC_ERR
> +
> +
>  class RemoteDirectoryExistsError(DTSError):
>      """A directory that exists on a remote node."""
>
> diff --git a/dts/framework/remote_session/interactive_shell.py b/dts/framework/remote_session/interactive_shell.py
> index 5cfe202e15..2bcfdcb3c7 100644
> --- a/dts/framework/remote_session/interactive_shell.py
> +++ b/dts/framework/remote_session/interactive_shell.py
> @@ -20,6 +20,7 @@
>
>  from paramiko import Channel, SSHClient, channel  # type: ignore[import]
>
> +from framework.exception import InteractiveCommandExecutionError
>  from framework.logger import DTSLogger
>  from framework.settings import SETTINGS
>
> @@ -124,6 +125,10 @@ def send_command(self, command: str, prompt: str | None = None) -> str:
>
>          Returns:
>              All output in the buffer before expected string.
> +
> +        Raises:
> +            InteractiveCommandExecutionError: If command was sent but prompt could not be found in
> +                the output.
>          """
>          self._logger.info(f"Sending: '{command}'")
>          if prompt is None:
> @@ -131,14 +136,19 @@ def send_command(self, command: str, prompt: str | None = None) -> str:
>          self._stdin.write(f"{command}{self._command_extra_chars}\n")
>          self._stdin.flush()
>          out: str = ""
> -        for line in self._stdout:
> -            out += line
> -            if prompt in line and not line.rstrip().endswith(
> -                command.rstrip()
> -            ):  # ignore line that sent command
> -                break
> -        self._logger.debug(f"Got output: {out}")
> -        return out
> +        try:
> +            for line in self._stdout:
> +                out += line
> +                if line.rstrip().endswith(prompt):
> +                    break
> +        except TimeoutError:

I like this addition, but maybe we could do better. In the regular SSH
session, we're expected to raise:
* SSHSessionDeadError if the session is not alive,
* SSHTimeoutError if the command execution times out.

Can we do that here as well?

> +            raise InteractiveCommandExecutionError(

We could just reuse the SSHTimeoutError exception. Is there a reason
to distinguish between interactive and non-interactive timeouts?

> +                f"Failed to find the prompt ({prompt}) at the end of a line in the output from the"
> +                f" command ({command}). Got:\n{out}"
> +            )
> +        else:
> +            self._logger.debug(f"Got output: {out}")
> +            return out
>
>      def close(self) -> None:
>          """Properly free all resources."""
> --
> 2.43.2
>

Re: [PATCH v1 1/2] dts: Improve output gathering in interactive shells

[Jeremy Spewock]

On Wed, Apr 3, 2024 at 5:00 AM Juraj Linkeš <juraj.linkes@pantheon.tech> wrote:
>
> On Tue, Mar 12, 2024 at 6:26 PM <jspewock@iol.unh.edu> wrote:
> >
> > From: Jeremy Spewock <jspewock@iol.unh.edu>
> >
> > The current implementation of consuming output from interactive shells
> > relies on being able to find an expected prompt somewhere within the
> > output buffer after sending the command. This is useful in situations
> > where the prompt does not appear in the output itself, but in some
> > practical cases (such as the starting of an XML-RPC server for scapy)
> > the prompt exists in one of the commands sent to the shell and this can
> > cause the command to exit early and creates a race condition between the
> > server starting and the first command being sent to the server.
> >
> > This patch addresses this problem by searching for a line that strictly
> > ends with the provided prompt, rather than one that simply contains it,
> > so that the detection that a command is finished is more consistent. It
> > also adds a catch to detect when a command times out before finding the
> > prompt so that the exception can be wrapped into a more explicit one and
> > display the output that it did manage to gather before timing out.
> >
>
> This could still cause problems if the prompt appears at the end of a
> line in the output. Maybe we don't need to worry about that until we
> actually hit that problem. In any case, I'd like to test this, so
> please rebase the patch. :-)

I will rebase and send out a v2, but that is a good point. it would be
just as easy to instead check to see that the prompt is the only thing
on the line, so we could do that instead, which do you think is
better? I'm sort of indifferent, I can see how verifying that the line
only contains the prompt would be useful in cases like it appears in a
docstring or something similar (and it's nice to be more explicit in
general), and I think that leaving it as the end of the line could
potentially save some verbosity if the line you are looking for is
long so you can just detect the end of it. Another problem that I
could think of with long lines potentially is if, somehow, you were
looking for a prompt that the pseudo-terminal split across a few lines
and it split your prompt, but I'm not sure this is really relevant to
us at all since we only really expect prompts that are usually short.

>
<snip>
> > +        try:
> > +            for line in self._stdout:
> > +                out += line
> > +                if line.rstrip().endswith(prompt):
> > +                    break
> > +        except TimeoutError:
>
> I like this addition, but maybe we could do better. In the regular SSH
> session, we're expected to raise:
> * SSHSessionDeadError if the session is not alive,
> * SSHTimeoutError if the command execution times out.
>
> Can we do that here as well?

This is a good point, I don't see why we couldn't and thinking about
it I like the idea of making this more consistent, good catch.

>
> > +            raise InteractiveCommandExecutionError(
>
> We could just reuse the SSHTimeoutError exception. Is there a reason
> to distinguish between interactive and non-interactive timeouts?

I wanted to add a distinction between interactive and non-interactive
just because in general the way we log messages when sending commands
to interactive shells looks pretty close to what it looks like when
you do the same for non-interactive, so if there was an error I
thought it might be more helpful in the logs to know which session you
were sending the command to when an error was encountered. Maybe,
however, a better approach to this would just be keep the exception
types the same but change the messages.

>
<snip>
> > 2.43.2
> >

Re: [PATCH v1 1/2] dts: Improve output gathering in interactive shells

[Juraj Linkeš]

On Mon, Apr 8, 2024 at 6:20 PM Jeremy Spewock <jspewock@iol.unh.edu> wrote:
>
> On Wed, Apr 3, 2024 at 5:00 AM Juraj Linkeš <juraj.linkes@pantheon.tech> wrote:
> >
> > On Tue, Mar 12, 2024 at 6:26 PM <jspewock@iol.unh.edu> wrote:
> > >
> > > From: Jeremy Spewock <jspewock@iol.unh.edu>
> > >
> > > The current implementation of consuming output from interactive shells
> > > relies on being able to find an expected prompt somewhere within the
> > > output buffer after sending the command. This is useful in situations
> > > where the prompt does not appear in the output itself, but in some
> > > practical cases (such as the starting of an XML-RPC server for scapy)
> > > the prompt exists in one of the commands sent to the shell and this can
> > > cause the command to exit early and creates a race condition between the
> > > server starting and the first command being sent to the server.
> > >
> > > This patch addresses this problem by searching for a line that strictly
> > > ends with the provided prompt, rather than one that simply contains it,
> > > so that the detection that a command is finished is more consistent. It
> > > also adds a catch to detect when a command times out before finding the
> > > prompt so that the exception can be wrapped into a more explicit one and
> > > display the output that it did manage to gather before timing out.
> > >
> >
> > This could still cause problems if the prompt appears at the end of a
> > line in the output. Maybe we don't need to worry about that until we
> > actually hit that problem. In any case, I'd like to test this, so
> > please rebase the patch. :-)
>
> I will rebase and send out a v2, but that is a good point. it would be
> just as easy to instead check to see that the prompt is the only thing
> on the line, so we could do that instead, which do you think is
> better?

Would this work? I'm thinking we may need to send another extra
newline character to put the solitary prompt into the buffer if the
command output doesn't contain a newline.

> I'm sort of indifferent, I can see how verifying that the line
> only contains the prompt would be useful in cases like it appears in a
> docstring or something similar (and it's nice to be more explicit in
> general), and I think that leaving it as the end of the line could
> potentially save some verbosity if the line you are looking for is
> long so you can just detect the end of it. Another problem that I
> could think of with long lines potentially is if, somehow, you were
> looking for a prompt that the pseudo-terminal split across a few lines
> and it split your prompt, but I'm not sure this is really relevant to
> us at all since we only really expect prompts that are usually short.
>

If it works with checking just the end of the line let's leave it like
this (because of the possibility above). I think there shouldn't be
any prompts without something after them in docstrings.

> >
> <snip>
> > > +        try:
> > > +            for line in self._stdout:
> > > +                out += line
> > > +                if line.rstrip().endswith(prompt):
> > > +                    break
> > > +        except TimeoutError:
> >
> > I like this addition, but maybe we could do better. In the regular SSH
> > session, we're expected to raise:
> > * SSHSessionDeadError if the session is not alive,
> > * SSHTimeoutError if the command execution times out.
> >
> > Can we do that here as well?
>
> This is a good point, I don't see why we couldn't and thinking about
> it I like the idea of making this more consistent, good catch.
>
> >
> > > +            raise InteractiveCommandExecutionError(
> >
> > We could just reuse the SSHTimeoutError exception. Is there a reason
> > to distinguish between interactive and non-interactive timeouts?
>
> I wanted to add a distinction between interactive and non-interactive
> just because in general the way we log messages when sending commands
> to interactive shells looks pretty close to what it looks like when
> you do the same for non-interactive, so if there was an error I
> thought it might be more helpful in the logs to know which session you
> were sending the command to when an error was encountered. Maybe,
> however, a better approach to this would just be keep the exception
> types the same but change the messages.
>

There is probably some value to distinguish between them. We could
just mirror the non-interactive exceptions and keep the messages the
same.

> >
> <snip>
> > > 2.43.2
> > >

Re: [PATCH v1 2/2] dts: Add missing docstring from XML-RPC server

[Patrick Robb]

[-- Attachment #1: Type: text/plain, Size: 30 bytes --]

Recheck-request: github-robot

[-- Attachment #2: Type: text/html, Size: 113 bytes --]

[PATCH v2 0/3] Improve interactive shell output gathering and logging

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

This version addresses comments from the last and adds an additional
improvement to the logging output that comes from interactive shells.
The new way of handling logging allows for not only specification of the
host that the command is being sent to like before, but also the type of
shell that you are addressing. This is beneficial for 2 reasons:

1. Less ambiguity on if a command is being sent to the host directly or
into an interactive shell
2. Ability to name shells so that there is distinction in the logs
between two different interactive shells of the same type that serve a
different purpose (e.g. a python shell and a python shell that is
serving and XML-RPC server for scapy interactions) 

Jeremy Spewock (3):
  dts: Improve output gathering in interactive shells
  dts: Add missing docstring from XML-RPC server
  dts: Improve logging for interactive shells

 dts/framework/exception.py                    | 66 ++++++++++++-------
 .../remote_session/interactive_shell.py       | 54 ++++++++++-----
 dts/framework/testbed_model/node.py           |  7 ++
 dts/framework/testbed_model/os_session.py     |  6 +-
 dts/framework/testbed_model/sut_node.py       |  7 +-
 .../testbed_model/traffic_generator/scapy.py  | 48 +++++++++++++-
 6 files changed, 145 insertions(+), 43 deletions(-)

-- 
2.44.0

[PATCH v2 1/3] dts: Improve output gathering in interactive shells

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

The current implementation of consuming output from interactive shells
relies on being able to find an expected prompt somewhere within the
output buffer after sending the command. This is useful in situations
where the prompt does not appear in the output itself, but in some
practical cases (such as the starting of an XML-RPC server for scapy)
the prompt exists in one of the commands sent to the shell and this can
cause the command to exit early and creates a race condition between the
server starting and the first command being sent to the server.

This patch addresses this problem by searching for a line that strictly
ends with the provided prompt, rather than one that simply contains it,
so that the detection that a command is finished is more consistent. It
also adds a catch to detect when a command times out before finding the
prompt or the underlying SSH session dies so that the exception can be
wrapped into a more explicit one and be more consistent with the
non-interactive shells.

Bugzilla ID: 1359
Fixes: 88489c0501af ("dts: add smoke tests")

Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
---
 dts/framework/exception.py                    | 66 ++++++++++++-------
 .../remote_session/interactive_shell.py       | 46 +++++++++----
 2 files changed, 77 insertions(+), 35 deletions(-)

diff --git a/dts/framework/exception.py b/dts/framework/exception.py
index cce1e0231a..627190c781 100644
--- a/dts/framework/exception.py
+++ b/dts/framework/exception.py
@@ -48,26 +48,6 @@ class DTSError(Exception):
     severity: ClassVar[ErrorSeverity] = ErrorSeverity.GENERIC_ERR
 
 
-class SSHTimeoutError(DTSError):
-    """The SSH execution of a command timed out."""
-
-    #:
-    severity: ClassVar[ErrorSeverity] = ErrorSeverity.SSH_ERR
-    _command: str
-
-    def __init__(self, command: str):
-        """Define the meaning of the first argument.
-
-        Args:
-            command: The executed command.
-        """
-        self._command = command
-
-    def __str__(self) -> str:
-        """Add some context to the string representation."""
-        return f"{self._command} execution timed out."
-
-
 class SSHConnectionError(DTSError):
     """An unsuccessful SSH connection."""
 
@@ -95,8 +75,42 @@ def __str__(self) -> str:
         return message
 
 
-class SSHSessionDeadError(DTSError):
-    """The SSH session is no longer alive."""
+class _SSHTimeoutError(DTSError):
+    """The execution of a command via SSH timed out.
+
+    This class is private and meant to be raised as its interactive and non-interactive variants.
+    """
+
+    #:
+    severity: ClassVar[ErrorSeverity] = ErrorSeverity.SSH_ERR
+    _command: str
+
+    def __init__(self, command: str):
+        """Define the meaning of the first argument.
+
+        Args:
+            command: The executed command.
+        """
+        self._command = command
+
+    def __str__(self) -> str:
+        """Add some context to the string representation."""
+        return f"{self._command} execution timed out."
+
+
+class SSHTimeoutError(_SSHTimeoutError):
+    """The execution of a command on a non-interactive SSH session timed out."""
+
+
+class InteractiveSSHTimeoutError(_SSHTimeoutError):
+    """The execution of a command on an interactive SSH session timed out."""
+
+
+class _SSHSessionDeadError(DTSError):
+    """The SSH session is no longer alive.
+
+    This class is private and meant to be raised as its interactive and non-interactive variants.
+    """
 
     #:
     severity: ClassVar[ErrorSeverity] = ErrorSeverity.SSH_ERR
@@ -115,6 +129,14 @@ def __str__(self) -> str:
         return f"SSH session with {self._host} has died."
 
 
+class SSHSessionDeadError(_SSHSessionDeadError):
+    """Non-interactive SSH session has died."""
+
+
+class InteractiveSSHSessionDeadError(_SSHSessionDeadError):
+    """Interactive SSH session as died."""
+
+
 class ConfigurationError(DTSError):
     """An invalid configuration."""
 
diff --git a/dts/framework/remote_session/interactive_shell.py b/dts/framework/remote_session/interactive_shell.py
index 5cfe202e15..0b0ccdb545 100644
--- a/dts/framework/remote_session/interactive_shell.py
+++ b/dts/framework/remote_session/interactive_shell.py
@@ -18,11 +18,17 @@
 from pathlib import PurePath
 from typing import Callable, ClassVar
 
-from paramiko import Channel, SSHClient, channel  # type: ignore[import]
+from paramiko import Channel, channel  # type: ignore[import]
 
+from framework.exception import (
+    InteractiveSSHSessionDeadError,
+    InteractiveSSHTimeoutError,
+)
 from framework.logger import DTSLogger
 from framework.settings import SETTINGS
 
+from .interactive_remote_session import InteractiveRemoteSession
+
 
 class InteractiveShell(ABC):
     """The base class for managing interactive shells.
@@ -34,7 +40,7 @@ class InteractiveShell(ABC):
     session.
     """
 
-    _interactive_session: SSHClient
+    _interactive_session: InteractiveRemoteSession
     _stdin: channel.ChannelStdinFile
     _stdout: channel.ChannelFile
     _ssh_channel: Channel
@@ -60,7 +66,7 @@ class InteractiveShell(ABC):
 
     def __init__(
         self,
-        interactive_session: SSHClient,
+        interactive_session: InteractiveRemoteSession,
         logger: DTSLogger,
         get_privileged_command: Callable[[str], str] | None,
         app_args: str = "",
@@ -80,7 +86,7 @@ def __init__(
                 and no output is gathered within the timeout, an exception is thrown.
         """
         self._interactive_session = interactive_session
-        self._ssh_channel = self._interactive_session.invoke_shell()
+        self._ssh_channel = self._interactive_session.session.invoke_shell()
         self._stdin = self._ssh_channel.makefile_stdin("w")
         self._stdout = self._ssh_channel.makefile("r")
         self._ssh_channel.settimeout(timeout)
@@ -124,20 +130,34 @@ def send_command(self, command: str, prompt: str | None = None) -> str:
 
         Returns:
             All output in the buffer before expected string.
+
+        Raises:
+            InteractiveSSHSessionDeadError: The session died while executing the command.
+            InteractiveSSHTimeoutError: If command was sent but prompt could not be found in
+                the output before the timeout.
         """
         self._logger.info(f"Sending: '{command}'")
         if prompt is None:
             prompt = self._default_prompt
-        self._stdin.write(f"{command}{self._command_extra_chars}\n")
-        self._stdin.flush()
         out: str = ""
-        for line in self._stdout:
-            out += line
-            if prompt in line and not line.rstrip().endswith(
-                command.rstrip()
-            ):  # ignore line that sent command
-                break
-        self._logger.debug(f"Got output: {out}")
+        try:
+            self._stdin.write(f"{command}{self._command_extra_chars}\n")
+            self._stdin.flush()
+            for line in self._stdout:
+                out += line
+                if line.rstrip().endswith(prompt):
+                    break
+        except TimeoutError as e:
+            self._logger.exception(e)
+            self._logger.debug(
+                f"Prompt ({prompt}) was not found in output from command before timeout."
+            )
+            raise InteractiveSSHTimeoutError(command) from e
+        except OSError as e:
+            self._logger.exception(e)
+            raise InteractiveSSHSessionDeadError(self._interactive_session.hostname) from e
+        finally:
+            self._logger.debug(f"Got output: {out}")
         return out
 
     def close(self) -> None:
-- 
2.44.0

[PATCH v2 2/3] dts: Add missing docstring from XML-RPC server

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

When this XML-RPC server implementation was added, the docstring had to
be shortened in order to reduce the chances of this race condition being
encountered. Now that this race condition issue is resolved, the full
docstring can be restored.

Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
---
 .../testbed_model/traffic_generator/scapy.py  | 46 ++++++++++++++++++-
 1 file changed, 45 insertions(+), 1 deletion(-)

diff --git a/dts/framework/testbed_model/traffic_generator/scapy.py b/dts/framework/testbed_model/traffic_generator/scapy.py
index df3069d516..d0e0a7c64e 100644
--- a/dts/framework/testbed_model/traffic_generator/scapy.py
+++ b/dts/framework/testbed_model/traffic_generator/scapy.py
@@ -128,9 +128,53 @@ def scapy_send_packets(xmlrpc_packets: list[xmlrpc.client.Binary], send_iface: s
 
 
 class QuittableXMLRPCServer(SimpleXMLRPCServer):
-    """Basic XML-RPC server.
+    r"""Basic XML-RPC server.
 
     The server may be augmented by functions serializable by the :mod:`marshal` module.
+
+    Example:
+        ::
+
+            def hello_world():
+                # to be sent to the XML-RPC server
+                print("Hello World!")
+
+            # start the XML-RPC server on the remote node
+            # the example assumes you're already connect to a tg_node
+            # this is done by starting a Python shell on the remote node
+            from framework.remote_session import PythonShell
+            session = tg_node.create_interactive_shell(PythonShell, timeout=5, privileged=True)
+
+            # then importing the modules needed to run the server
+            # and the modules for any functions later added to the server
+            session.send_command("import xmlrpc")
+            session.send_command("from xmlrpc.server import SimpleXMLRPCServer")
+
+            # sending the source code of this class to the Python shell
+            from xmlrpc.server import SimpleXMLRPCServer
+            src = inspect.getsource(QuittableXMLRPCServer)
+            src = "\n".join([l for l in src.splitlines() if not l.isspace() and l != ""])
+            spacing = "\n" * 4
+            session.send_command(spacing + src + spacing)
+
+            # then starting the server with:
+            command = "s = QuittableXMLRPCServer(('0.0.0.0', {listen_port}));s.serve_forever()"
+            session.send_command(command, "XMLRPC OK")
+
+            # now the server is running on the remote node and we can add functions to it
+            # first connect to the server from the execution node
+            import xmlrpc.client
+            server_url = f"http://{tg_node.config.hostname}:8000"
+            rpc_server_proxy = xmlrpc.client.ServerProxy(server_url)
+
+            # get the function bytes to send
+            import marshal
+            function_bytes = marshal.dumps(hello_world.__code__)
+            rpc_server_proxy.add_rpc_function(hello_world.__name__, function_bytes)
+
+            # now we can execute the function on the server
+            xmlrpc_binary_recv: xmlrpc.client.Binary = rpc_server_proxy.hello_world()
+            print(str(xmlrpc_binary_recv))
     """
 
     def __init__(self, *args, **kwargs):
-- 
2.44.0

[PATCH v2 3/3] dts: Improve logging for interactive shells

[jspewock]

From: Jeremy Spewock <jspewock@iol.unh.edu>

The messages being logged by interactive shells currently are using the
same logger as the node they were created from. Because of this, when
sending interactive commands, the logs make no distinction between when
you are sending a command directly to the host and when you are using an
interactive shell on the host. This change adds names to interactive
shells so that they are able to use their own loggers with distinct
names.

Signed-off-by: Jeremy Spewock <jspewock@iol.unh.edu>
---
 dts/framework/remote_session/interactive_shell.py      | 9 +++++----
 dts/framework/testbed_model/node.py                    | 7 +++++++
 dts/framework/testbed_model/os_session.py              | 6 ++++--
 dts/framework/testbed_model/sut_node.py                | 7 ++++++-
 dts/framework/testbed_model/traffic_generator/scapy.py | 2 +-
 5 files changed, 23 insertions(+), 8 deletions(-)

diff --git a/dts/framework/remote_session/interactive_shell.py b/dts/framework/remote_session/interactive_shell.py
index 0b0ccdb545..eb9c9b6843 100644
--- a/dts/framework/remote_session/interactive_shell.py
+++ b/dts/framework/remote_session/interactive_shell.py
@@ -24,7 +24,7 @@
     InteractiveSSHSessionDeadError,
     InteractiveSSHTimeoutError,
 )
-from framework.logger import DTSLogger
+from framework.logger import DTSLogger, get_dts_logger
 from framework.settings import SETTINGS
 
 from .interactive_remote_session import InteractiveRemoteSession
@@ -66,8 +66,8 @@ class InteractiveShell(ABC):
 
     def __init__(
         self,
+        name: str,
         interactive_session: InteractiveRemoteSession,
-        logger: DTSLogger,
         get_privileged_command: Callable[[str], str] | None,
         app_args: str = "",
         timeout: float = SETTINGS.timeout,
@@ -75,8 +75,9 @@ def __init__(
         """Create an SSH channel during initialization.
 
         Args:
+            name: Name for the interactive shell to use for logging. This name will be appended to
+                the name of the underlying node which it is running on.
             interactive_session: The SSH session dedicated to interactive shells.
-            logger: The logger instance this session will use.
             get_privileged_command: A method for modifying a command to allow it to use
                 elevated privileges. If :data:`None`, the application will not be started
                 with elevated privileges.
@@ -91,7 +92,7 @@ def __init__(
         self._stdout = self._ssh_channel.makefile("r")
         self._ssh_channel.settimeout(timeout)
         self._ssh_channel.set_combine_stderr(True)  # combines stdout and stderr streams
-        self._logger = logger
+        self._logger = get_dts_logger(f"{interactive_session._node_config.name}.{name}")
         self._timeout = timeout
         self._app_args = app_args
         self._start_application(get_privileged_command)
diff --git a/dts/framework/testbed_model/node.py b/dts/framework/testbed_model/node.py
index 74061f6262..a5beeae7e7 100644
--- a/dts/framework/testbed_model/node.py
+++ b/dts/framework/testbed_model/node.py
@@ -199,6 +199,7 @@ def create_interactive_shell(
         shell_cls: Type[InteractiveShellType],
         timeout: float = SETTINGS.timeout,
         privileged: bool = False,
+        name: str = "",
         app_args: str = "",
     ) -> InteractiveShellType:
         """Factory for interactive session handlers.
@@ -210,6 +211,8 @@ def create_interactive_shell(
             timeout: Timeout for reading output from the SSH channel. If you are reading from
                 the buffer and don't receive any data within the timeout it will throw an error.
             privileged: Whether to run the shell with administrative privileges.
+            name: The name to use for the interactive application in the logs. If not specified,
+                this will default to the name of `shell_cls`.
             app_args: The arguments to be passed to the application.
 
         Returns:
@@ -218,10 +221,14 @@ def create_interactive_shell(
         if not shell_cls.dpdk_app:
             shell_cls.path = self.main_session.join_remote_path(shell_cls.path)
 
+        if name == "":
+            name = shell_cls.__name__
+
         return self.main_session.create_interactive_shell(
             shell_cls,
             timeout,
             privileged,
+            name,
             app_args,
         )
 
diff --git a/dts/framework/testbed_model/os_session.py b/dts/framework/testbed_model/os_session.py
index d5bf7e0401..1f6d8257ed 100644
--- a/dts/framework/testbed_model/os_session.py
+++ b/dts/framework/testbed_model/os_session.py
@@ -134,6 +134,7 @@ def create_interactive_shell(
         shell_cls: Type[InteractiveShellType],
         timeout: float,
         privileged: bool,
+        name: str,
         app_args: str,
     ) -> InteractiveShellType:
         """Factory for interactive session handlers.
@@ -146,14 +147,15 @@ def create_interactive_shell(
                 reading from the buffer and don't receive any data within the timeout
                 it will throw an error.
             privileged: Whether to run the shell with administrative privileges.
+            name: Name for the shell to use in the logs.
             app_args: The arguments to be passed to the application.
 
         Returns:
             An instance of the desired interactive application shell.
         """
         return shell_cls(
-            self.interactive_session.session,
-            self._logger,
+            name,
+            self.interactive_session,
             self._get_privileged_command if privileged else None,
             app_args,
             timeout,
diff --git a/dts/framework/testbed_model/sut_node.py b/dts/framework/testbed_model/sut_node.py
index 97aa26d419..0bddef6f44 100644
--- a/dts/framework/testbed_model/sut_node.py
+++ b/dts/framework/testbed_model/sut_node.py
@@ -442,6 +442,7 @@ def create_interactive_shell(
         shell_cls: Type[InteractiveShellType],
         timeout: float = SETTINGS.timeout,
         privileged: bool = False,
+        name: str = "",
         app_parameters: str = "",
         eal_parameters: EalParameters | None = None,
     ) -> InteractiveShellType:
@@ -459,6 +460,8 @@ def create_interactive_shell(
                 reading from the buffer and don't receive any data within the timeout
                 it will throw an error.
             privileged: Whether to run the shell with administrative privileges.
+            name: The name to use for the interactive application in the logs. If not specified,
+                this will default to the name `shell_cls`.
             eal_parameters: List of EAL parameters to use to launch the app. If this
                 isn't provided or an empty string is passed, it will default to calling
                 :meth:`create_eal_parameters`.
@@ -478,7 +481,9 @@ def create_interactive_shell(
                 self.remote_dpdk_build_dir, shell_cls.path
             )
 
-        return super().create_interactive_shell(shell_cls, timeout, privileged, app_parameters)
+        return super().create_interactive_shell(
+            shell_cls, timeout, privileged, name, app_parameters
+        )
 
     def bind_ports_to_driver(self, for_dpdk: bool = True) -> None:
         """Bind all ports on the SUT to a driver.
diff --git a/dts/framework/testbed_model/traffic_generator/scapy.py b/dts/framework/testbed_model/traffic_generator/scapy.py
index d0e0a7c64e..5676235119 100644
--- a/dts/framework/testbed_model/traffic_generator/scapy.py
+++ b/dts/framework/testbed_model/traffic_generator/scapy.py
@@ -262,7 +262,7 @@ def __init__(self, tg_node: Node, config: ScapyTrafficGeneratorConfig):
         ), "Linux is the only supported OS for scapy traffic generation"
 
         self.session = self._tg_node.create_interactive_shell(
-            PythonShell, timeout=5, privileged=True
+            PythonShell, timeout=5, privileged=True, name="ScapyXMLRPCServer"
         )
 
         # import libs in remote python console
-- 
2.44.0

Re: [PATCH v2 1/3] dts: Improve output gathering in interactive shells

[Luca Vizzarro]

Reviewed-by: Luca Vizzarro <luca.vizzarro@arm.com>

Re: [PATCH v2 2/3] dts: Add missing docstring from XML-RPC server

[Luca Vizzarro]

Reviewed-by: Luca Vizzarro <luca.vizzarro@arm.com>

Re: [PATCH v2 3/3] dts: Improve logging for interactive shells

[Luca Vizzarro]

Reviewed-by: Luca Vizzarro <luca.vizzarro@arm.com>

Re: [PATCH v2 0/3] Improve interactive shell output gathering and logging

[Luca Vizzarro]

On 01/05/2024 17:16, jspewock@iol.unh.edu wrote:
> This version addresses comments from the last and adds an additional
> improvement to the logging output that comes from interactive shells.
> The new way of handling logging allows for not only specification of the
> host that the command is being sent to like before, but also the type of
> shell that you are addressing. This is beneficial for 2 reasons:
> 
> 1. Less ambiguity on if a command is being sent to the host directly or
> into an interactive shell
> 2. Ability to name shells so that there is distinction in the logs
> between two different interactive shells of the same type that serve a
> different purpose (e.g. a python shell and a python shell that is
> serving and XML-RPC server for scapy interactions)

Hi Jeremy,

Thank you for your patches! Everything looks good to me.

Best,
Luca