tests: log all cmds input/output

Add Python's logger framework and log all commands input/output, in
order to be able to debug failures.

Signed-off-by: Daniel Wagner <[email protected]>

Author: igaw

tests/config.json

@@ -1,5 +1,6 @@
 {
 	"controller" : "/dev/nvme0",
         "ns1": "/dev/nvme0n1",
-	"log_dir": "nvmetests/"
+	"log_dir": "nvmetests",
+	"log_level": "DEBUG"
 }

tests/nvme_copy_test.py

@@ -16,10 +16,13 @@
 
 """
 
+import logging
 import subprocess
 
 from nvme_test import TestNVMe
 
+logger = logging.getLogger(__name__)
+
 
 class TestNVMeCopy(TestNVMe):
 
@@ -41,6 +44,7 @@ def setUp(self):
             # get host behavior support data
             get_features_cmd = f"{self.nvme_bin} get-feature {self.ctrl} " + \
                 "--feature-id=0x16 --data-len=512 --raw-binary"
+            logger.debug(get_features_cmd)
             proc = subprocess.Popen(get_features_cmd,
                                     shell=True,
                                     stdout=subprocess.PIPE,
@@ -65,13 +69,15 @@ def setUp(self):
                 proc.communicate(input=data)
                 self.assertEqual(proc.returncode, 0, "Failed to enable cross-namespace copy formats")
         get_ns_id_cmd = f"{self.nvme_bin} get-ns-id {self.ns1}"
+        logger.debug(get_ns_id_cmd)
         proc = subprocess.Popen(get_ns_id_cmd,
                                 shell=True,
                                 stdout=subprocess.PIPE,
                                 encoding='utf-8')
         err = proc.wait()
         self.assertEqual(err, 0, "ERROR : nvme get-ns-id failed")
         output = proc.stdout.read()
+        logger.debug(output)
         self.ns1_nsid = int(output.strip().split(':')[-1])
         self.setup_log_dir(self.__class__.__name__)
 
@@ -81,6 +87,7 @@ def tearDown(self):
             # restore saved host behavior support data
             set_features_cmd = f"{self.nvme_bin} set-feature {self.ctrl} " + \
                 "--feature-id=0x16 --data-len=512"
+            logger.debug(set_features_cmd)
             proc = subprocess.Popen(set_features_cmd,
                                     shell=True,
                                     stdout=subprocess.PIPE,

tests/nvme_format_test.py

@@ -38,11 +38,14 @@
 """
 
 import json
+import logging
 import math
 import subprocess
 
 from nvme_test import TestNVMe
 
+logger = logging.getLogger(__name__)
+
 
 class TestNVMeFormatCmd(TestNVMe):
 
@@ -107,13 +110,16 @@ def attach_detach_primary_ns(self):
         # read lbaf information
         id_ns_cmd = f"{self.nvme_bin} id-ns {self.ctrl} " + \
             f"--namespace-id={self.default_nsid} --output-format=json"
+        logger.debug(id_ns_cmd)
         proc = subprocess.Popen(id_ns_cmd,
                                 shell=True,
                                 stdout=subprocess.PIPE,
                                 encoding='utf-8')
         err = proc.wait()
         self.assertEqual(err, 0, "ERROR : nvme id-ns failed")
-        json_output = json.loads(proc.stdout.read())
+        output = proc.stdout.read()
+        logger.debug(output)
+        json_output = json.loads(output)
         self.lba_format_list = json_output['lbafs']
         self.assertTrue(len(self.lba_format_list) > 0,
                         "ERROR : nvme id-ns could not find any lba formats")

tests/nvme_get_features_test.py

@@ -34,10 +34,13 @@
     9. 0Bh M Asynchronous Event Configuration.
 """
 
+import logging
 import subprocess
 
 from nvme_test import TestNVMe
 
+logger = logging.getLogger(__name__)
+
 
 class TestNVMeGetMandatoryFeatures(TestNVMe):
 
@@ -59,11 +62,14 @@ def setUp(self):
         device = self.ctrl.split('/')[-1]
         get_vector_list_cmd = "grep " + device + "q /proc/interrupts |" \
                               " cut -d : -f 1 | tr -d ' ' | tr '\n' ' '"
+        logger.debug(get_vector_list_cmd)
         proc = subprocess.Popen(get_vector_list_cmd,
                                 shell=True,
                                 stdout=subprocess.PIPE,
                                 encoding='utf-8')
-        self.vector_list_len = len(proc.stdout.read().strip().split(" "))
+        output = proc.stdout.read()
+        logger.debug(output)
+        self.vector_list_len = len(output.strip().split(" "))
 
     def tearDown(self):
         """ Post Section for TestNVMeGetMandatoryFeatures