driver/rawnetworkinterfacedriver: improve debugging experience

helpers/labgrid-raw-interface

@@ -9,6 +9,7 @@
 
 import argparse
 import os
+import shlex
 import string
 import sys
 import subprocess
@@ -183,9 +184,16 @@ def main(program, options):
             args.extend(options.ethtool_pause_args)
 
     elif program == "ns-macvtap":
+        if options.dry_run:
+            raise NotImplementedError("ns-macvtap does not support dry run")
+
         handle_ns_macvtap(options)
         return
 
+    if options.dry_run:
+        print(shlex.join(args))
+        return
+
     try:
         os.execvp(args[0], args)
     except FileNotFoundError as e:
@@ -195,6 +203,7 @@ def main(program, options):
 if __name__ == "__main__":
     parser = argparse.ArgumentParser()
     parser.add_argument("-d", "--debug", action="store_true", default=False, help="enable debug mode")
+    parser.add_argument("--dry-run", action="store_true", default=False, help="shows what command would be executed")
     subparsers = parser.add_subparsers(dest="program", help="program to run")
 
     # tcpdump

labgrid/driver/rawnetworkinterfacedriver.py

@@ -1,6 +1,7 @@
 # pylint: disable=no-member
 import contextlib
 import json
+import logging
 import subprocess
 import time
 import os
@@ -51,21 +52,35 @@ def on_deactivate(self):
             self._wait_state("down")
 
     def _wrap_command(self, args):
-        wrapper = ["sudo", "labgrid-raw-interface"]
+        def _wrap(args, extra_arg=None):
+            cmd = ["sudo", "labgrid-raw-interface"]
+            if extra_arg is not None:
+                cmd.append(extra_arg)
+            cmd += args
 
-        if self.iface.command_prefix:
-            # add ssh prefix, convert command passed via ssh (including wrapper) to single argument
-            return self.iface.command_prefix + [" ".join(wrapper + args)]
-        else:
-            # keep wrapper and args as-is
-            return wrapper + args
+            if self.iface.command_prefix:
+                # add ssh prefix, convert command passed via ssh (including wrapper) to single argument
+                cmd = self.iface.command_prefix + [" ".join(cmd)]
+
+            return cmd
+
+        if self.logger.isEnabledFor(logging.DEBUG):
+            try:
+                original_call = subprocess.check_output(_wrap(args, "--dry-run"), text=True).rstrip()
+                host = getattr(self.iface, "host", "localhost")
+                self.logger.debug("running '%s' on %s via labgrid-raw-interface", original_call, host)
+            except subprocess.CalledProcessError:
+                # not all sub commands support dry run
+                pass
+
+        return _wrap(args)
 
     @step(args=["state"])
     def _set_interface(self, state):
         """Set interface to given state."""
         cmd = ["ip", self.iface.ifname, state]
         cmd = self._wrap_command(cmd)
-        subprocess.check_call(cmd)
+        processwrapper.check_output(cmd)
 
     @Driver.check_active
     def set_interface_up(self):
@@ -118,7 +133,8 @@ def get_ethtool_settings(self):
         Returns settings via ethtool of the bound network interface resource.
         """
         cmd = self.iface.command_prefix + ["ethtool", "--json", self.iface.ifname]
-        output = subprocess.check_output(cmd, encoding="utf-8")
+        # ignore netlink error: Operation not permitted, relevant info is still emitted
+        output = processwrapper.check_output(cmd, stderr=None).decode("utf-8")
         return json.loads(output)[0]
 
     @Driver.check_active
@@ -132,7 +148,7 @@ def ethtool_configure(self, **settings):
         cmd = ["ethtool", "change", self.iface.ifname]
         cmd += [item.replace("_", "-") for pair in settings.items() for item in pair]
         cmd = self._wrap_command(cmd)
-        subprocess.check_call(cmd)
+        processwrapper.check_output(cmd)
 
     @Driver.check_active
     def get_ethtool_eee_settings(self):
@@ -141,7 +157,7 @@ def get_ethtool_eee_settings(self):
         resource.
         """
         cmd = self.iface.command_prefix + ["ethtool", "--json", "--show-eee", self.iface.ifname]
-        output = subprocess.check_output(cmd, encoding="utf-8")
+        output = processwrapper.check_output(cmd).decode("utf-8")
         return json.loads(output)[0]
 
     @Driver.check_active
@@ -156,15 +172,15 @@ def ethtool_configure_eee(self, **settings):
         cmd = ["ethtool", "set-eee", self.iface.ifname]
         cmd += [item.replace("_", "-") for pair in settings.items() for item in pair]
         cmd = self._wrap_command(cmd)
-        subprocess.check_call(cmd)
+        processwrapper.check_output(cmd)
 
     @Driver.check_active
     def get_ethtool_pause_settings(self):
         """
         Returns pause parameters via ethtool of the bound network interface resource.
         """
         cmd = self.iface.command_prefix + ["ethtool", "--json", "--show-pause", self.iface.ifname]
-        output = subprocess.check_output(cmd, encoding="utf-8")
+        output = processwrapper.check_output(cmd).decode("utf-8")
         return json.loads(output)[0]
 
     @Driver.check_active
@@ -178,7 +194,7 @@ def ethtool_configure_pause(self, **settings):
         cmd = ["ethtool", "pause", self.iface.ifname]
         cmd += [item for pair in settings.items() for item in pair]
         cmd = self._wrap_command(cmd)
-        subprocess.check_call(cmd)
+        processwrapper.check_output(cmd)
 
     def _stop(self, proc, *, timeout=None):
         assert proc is not None
@@ -220,9 +236,11 @@ def start_record(self, filename, *, count=None, timeout=None):
             cmd.append(str(timeout))
         cmd = self._wrap_command(cmd)
         if filename is None:
+            self.logger.debug("running %s", cmd)
             self._record_handle = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
         else:
             with open(filename, "wb") as outdata:
+                self.logger.debug("running %s", cmd)
                 self._record_handle = subprocess.Popen(cmd, stdout=outdata, stderr=subprocess.PIPE)
 
         # wait for capture start
@@ -306,10 +324,12 @@ def start_replay(self, filename):
             mf = ManagedFile(filename, self.iface)
             mf.sync_to_resource()
             cmd = self._wrap_command([f"tcpreplay {self.iface.ifname} < {mf.get_remote_path()}"])
+            self.logger.debug("running %s", cmd)
             self._replay_handle = subprocess.Popen(cmd, stderr=subprocess.PIPE)
         else:
             cmd = self._wrap_command(["tcpreplay", self.iface.ifname])
             with open(filename, "rb") as indata:
+                self.logger.debug("running %s", cmd)
                 self._replay_handle = subprocess.Popen(cmd, stdin=indata)
 
         return self._replay_handle
@@ -388,9 +408,11 @@ def setup_netns(self, mac_address=None):
                 cmd.append(mac_address)
 
             # Start tap forward in remote namespace
+            cmd = self._wrap_command(cmd)
+            self.logger.debug("running %s", cmd)
             remote_fwd = ctx.enter_context(
                 subprocess.Popen(
-                    self._wrap_command(cmd),
+                    cmd,
                     stdout=subprocess.PIPE,
                     stdin=subprocess.PIPE,
                 )
@@ -429,9 +451,11 @@ def setup_netns(self, mac_address=None):
             link_names = [link["ifname"] for link in links]
             assert "tap0" in link_names
 
+            cmd = local_ns.get_prefix() + ["labgrid-tap-fwd", str(tun_fd.fileno())]
+            self.logger.debug("running %s", cmd)
             local_fwd = ctx.enter_context(
                 subprocess.Popen(
-                    local_ns.get_prefix() + ["labgrid-tap-fwd", str(tun_fd.fileno())],
+                    cmd,
                     stdin=remote_fwd.stdout,
                     stdout=remote_fwd.stdin,
                     pass_fds=(tun_fd.fileno(),),