[change] CommandTimeoutException on ssh command timeout

Author: Alexandre Vincent

openwisp_controller/connection/connectors/exceptions.py

@@ -4,3 +4,11 @@ class CommandFailedException(Exception):
     """
 
     pass
+
+
+class CommandTimeoutException(Exception):
+    """
+    raised when a command times out
+    """
+
+    pass

openwisp_controller/connection/connectors/ssh.py

@@ -11,7 +11,7 @@
 from scp import SCPClient
 
 from .. import settings as app_settings
-from .exceptions import CommandFailedException
+from .exceptions import CommandFailedException, CommandTimeoutException
 
 logger = logging.getLogger(__name__)
 
@@ -184,6 +184,9 @@ def exec_command(
         - aborts on exceptions
         - raises socket.timeout exceptions
         """
+        # paramiko expects timeout as a float
+        timeout = float(timeout)
+
         logger.info("Executing command: {0}".format(command))
         # execute commmand
         try:
@@ -197,17 +200,16 @@ def exec_command(
         except Exception as e:
             logger.exception(e)
             raise e
-        # store command exit status
-        exit_status = None
+
         # workaround https://github.com/paramiko/paramiko/issues/1815
         # workaround https://github.com/paramiko/paramiko/issues/1787
         # Ref. https://docs.paramiko.org/en/stable/api/channel.html#paramiko.channel.Channel.recv_exit_status  # noqa
         if not stdout.channel.status_event.wait(
-            timeout=timeout - int(time.perf_counter() - start_cmd)
+            timeout=timeout - (time.perf_counter() - start_cmd)
         ):
-            output = "Command timeout exceeded."
-            logger.info(output)
-            return output, -1
+            log_message = "Command timeout exceeded."
+            logger.info(log_message)
+            raise CommandTimeoutException(log_message)
 
         exit_status = stdout.channel.exit_status
         # log standard output

openwisp_controller/connection/tasks.py

@@ -9,6 +9,7 @@
 from swapper import load_model
 
 from . import settings as app_settings
+from .connectors.exceptions import CommandTimeoutException
 from .exceptions import NoWorkingDeviceConnectionError
 
 logger = logging.getLogger(__name__)
@@ -76,6 +77,10 @@ def launch_command(command_id):
         command.status = "failed"
         command._add_output(_("Background task time limit exceeded."))
         command.save()
+    except CommandTimeoutException as e:
+        command.status = "failed"
+        command._add_output(_(f"{e}"))
+        command.save()
     except Exception as e:
         logger.exception(
             f"An exception was raised while executing command {command_id}"

openwisp_controller/connection/tests/test_ssh.py

@@ -76,12 +76,12 @@ def test_connection_command_timeout(self, mocked_debug, mocked_info):
         ckey = self._create_credentials_with_key(port=self.ssh_server.port)
         dc = self._create_device_connection(credentials=ckey)
         dc.connector_instance.connect()
-        dc.connector_instance.exec_command("sleep 1", timeout=0)
-        mocked_info.assert_has_calls(
-            [
-                mock.call("Command timeout exceeded."),
-            ]
-        )
+        with self.assertRaises(Exception) as ctx:
+            # timeout of 0.0 is a special case in paramiko -> we check for 0.01 instead
+            dc.connector_instance.exec_command("sleep 1", timeout=0.01)
+        log_message = "Command timeout exceeded."
+        mocked_info.assert_has_calls([mock.call(log_message)])
+        self.assertEqual(str(ctx.exception), log_message)
 
     @mock.patch.object(ssh_logger, "info")
     @mock.patch.object(ssh_logger, "debug")