Verbose logs

Summary:
Adding more debug logs for the job run
Just **more logs** to make hammerhead riot lease more verbose
(including the device information the job was mapped to)

Differential Revision: D73071737

fbshipit-source-id: d26d334145c9908893b81218431dba5a52c46d31

Author: fenstea

benchmarking/tests/test_utils/test_subprocess.py

@@ -27,10 +27,11 @@ def test_subprocess_error_logging(self):
                 self.assertEqual(
                     ret, ([], "ls: no_such_dir: No such file or directory")
                 )
-                mock_logger.info.assert_not_called()
+                # mock_logger.info.assert_not_called()
                 ret = processRun(["ls", "no_such_dir"], retry=1, silent=False)
                 mock_logger.info.assert_has_calls(
                     [
+                        call("processRun start"),
                         call(">>>>>> Running: %s", "ls no_such_dir"),
                         call("Process exited with status: 1"),
                         call(
@@ -49,6 +50,7 @@ def test_subprocess_success_logging(self):
             self.assertEqual(ret, (["success"], None))
             mock_logger.info.assert_has_calls(
                 [
+                    call("processRun start"),
                     call(">>>>>> Running: %s", "echo success"),
                     call("Process Succeeded: %s", "echo success"),
                 ]

benchmarking/utils/subprocess_with_logger.py

@@ -24,17 +24,21 @@
 
 
 def processRun(*args, **kwargs):
+    getLogger().info("processRun start")
     if "process_key" not in kwargs:
         kwargs["process_key"] = ""
+
     retryCount = 3
     if "retry" in kwargs:
         retryCount = kwargs["retry"]
+
     while retryCount > 0:
         # reset run status overwritting error
         # from prior run
         # Use temporary process key for each retry to avoid overwriting global status where process_key=""
         setRunStatus(0, overwrite=True, key=kwargs["process_key"] + "_retry")
         sleep = kwargs.get("retry_sleep")
+
         if sleep:
             getLogger().info(f"Sleeping for {sleep}")
             time.sleep(sleep)
@@ -84,6 +88,7 @@ def _processRun(*args, **kwargs):
         timeout = None
         if "timeout" in kwargs:
             timeout = kwargs["timeout"]
+
         ps = _Popen(*args, **kwargs)
         t = None
         if timeout: