Add --logging_level option to crosperf.

Add --logging_level={verbose, average, quiet} option to crosperf,
optionally reducing the amount of logging output.  "verbose" gives
the same output Crosperf always gave; "quiet" gives minimal output, and
"average" is in the middle. The default for now is "verbose". Doing this
also involved adding logging levels to the command_executer, and to
image_chromeos (again, with the default being "verbose").

BUG=None
TEST=Tested all three levels of logging, with and without having to
reimage the DUT.  It all worked properly.

Change-Id: Icf8c9a6831fe25202adcb624c6c7e1d1a7ac25a5
Reviewed-on: https://chrome-internal-review.googlesource.com/156883
Reviewed-by: Caroline Tice <cmtice@google.com>
Commit-Queue: Caroline Tice <cmtice@google.com>
Tested-by: Caroline Tice <cmtice@google.com>

10 files changed, 140 insertions, 47 deletions

diff --git a/crosperf/benchmark_run.py b/crosperf/benchmark_run.py
index fa40997c..7e615430 100644
--- a/crosperf/benchmark_run.py
+++ b/crosperf/benchmark_run.py
@@ -35,10 +35,12 @@ class BenchmarkRun(threading.Thread):
                cache_conditions,
                machine_manager,
                logger_to_use,
+               log_level,
                share_users):
     threading.Thread.__init__(self)
     self.name = name
     self._logger = logger_to_use
+    self.log_level = log_level
     self.benchmark = benchmark
     self.iteration = iteration
     self.label = label
@@ -47,7 +49,7 @@ class BenchmarkRun(threading.Thread):
     self.retval = None
     self.run_completed = False
     self.machine_manager = machine_manager
-    self.suite_runner = SuiteRunner(self._logger)
+    self.suite_runner = SuiteRunner(self._logger, self.log_level)
     self.machine = None
     self.cache_conditions = cache_conditions
     self.runs_complete = 0
@@ -55,7 +57,8 @@ class BenchmarkRun(threading.Thread):
     self.failure_reason = ""
     self.test_args = benchmark.test_args
     self.profiler_args = self._GetExtraAutotestArgs()
-    self._ce = command_executer.GetCommandExecuter(self._logger)
+    self._ce = command_executer.GetCommandExecuter(self._logger,
+                                                   log_level=self.log_level)
     self.timeline = timeline.Timeline()
     self.timeline.Record(STATUS_PENDING)
     self.share_users = share_users
@@ -74,6 +77,7 @@ class BenchmarkRun(threading.Thread):
                     self.label.board,
                     self.cache_conditions,
                     self._logger,
+                    self.log_level,
                     self.label,
                     self.share_users,
                     self.benchmark.suite,
@@ -185,6 +189,7 @@ class BenchmarkRun(threading.Thread):
                                                   self.profiler_args)
     self.run_completed = True
     return Result.CreateFromRun(self._logger,
+                                self.log_level,
                                 self.label,
                                 out,
                                 err,
@@ -214,6 +219,7 @@ class MockBenchmarkRun(BenchmarkRun):
                     self.label.board,
                     self.cache_conditions,
                     self._logger,
+                    self.log_level,
                     self.label,
                     self.share_users,
                     self.benchmark.suite,
diff --git a/crosperf/experiment.py b/crosperf/experiment.py
index ec0b20e9..aa564559 100644
--- a/crosperf/experiment.py
+++ b/crosperf/experiment.py
@@ -24,7 +24,7 @@ class Experiment(object):
   def __init__(self, name, remote, working_directory,
                chromeos_root, cache_conditions, labels, benchmarks,
                experiment_file, email_to, acquire_timeout, log_dir,
-               share_users, results_directory):
+               log_level, share_users, results_directory):
     self.name = name
     self.working_directory = working_directory
     self.remote = remote
@@ -38,6 +38,7 @@ class Experiment(object):
     else:
       self.results_directory = misc.CanonicalizePath(results_directory)
     self.log_dir = log_dir
+    self.log_level = log_level
     self.labels = labels
     self.benchmarks = benchmarks
     self.num_complete = 0
@@ -55,9 +56,11 @@ class Experiment(object):
                       "the image path.")
 
     if test_flag.GetTestMode():
-      self.machine_manager = MockMachineManager(chromeos_root, acquire_timeout)
+      self.machine_manager = MockMachineManager(chromeos_root, acquire_timeout,
+                                                log_level)
     else:
-      self.machine_manager = MachineManager(chromeos_root, acquire_timeout)
+      self.machine_manager = MachineManager(chromeos_root, acquire_timeout,
+                                            log_level)
     self.l = logger.GetLogger(log_dir)
 
     for machine in remote:
@@ -81,7 +84,8 @@ class Experiment(object):
           full_name = "%s_%s_%s" % (label.name, benchmark.name, iteration)
           logger_to_use = logger.Logger(self.log_dir,
                                         "run.%s" % (full_name),
-                                        True)
+                                        True,
+                                        self.log_level)
           benchmark_run = BenchmarkRun(benchmark_run_name,
                                        benchmark,
                                        label,
@@ -89,6 +93,7 @@ class Experiment(object):
                                        self.cache_conditions,
                                        self.machine_manager,
                                        logger_to_use,
+                                       self.log_level,
                                        self.share_users)
 
           benchmark_runs.append(benchmark_run)
diff --git a/crosperf/experiment_factory.py b/crosperf/experiment_factory.py
index 86118a38..ac9e6ef2 100644
--- a/crosperf/experiment_factory.py
+++ b/crosperf/experiment_factory.py
@@ -141,6 +141,9 @@ class ExperimentFactory(object):
       suite = benchmark_settings.GetField("suite")
       use_test_that = benchmark_settings.GetField("use_test_that")
       show_all_results = benchmark_settings.GetField("show_all_results")
+      log_level = benchmark_settings.GetField("logging_level")
+      if log_level not in ("quiet", "average", "verbose"):
+        log_level = "verbose"
 
       if suite == 'telemetry_Crosperf':
         if test_name == 'all_perfv2':
@@ -226,7 +229,8 @@ class ExperimentFactory(object):
                             working_directory, chromeos_root,
                             cache_conditions, labels, benchmarks,
                             experiment_file.Canonicalize(),
-                            email, acquire_timeout, log_dir, share_users,
+                            email, acquire_timeout, log_dir, log_level,
+                            share_users,
                             results_dir)
 
     return experiment
diff --git a/crosperf/experiment_runner.py b/crosperf/experiment_runner.py
index 9212ba56..002fae3a 100644
--- a/crosperf/experiment_runner.py
+++ b/crosperf/experiment_runner.py
@@ -29,21 +29,39 @@ class ExperimentRunner(object):
     self.l = logger.GetLogger(experiment.log_dir)
     self._ce = command_executer.GetCommandExecuter(self.l)
     self._terminated = False
+    if experiment.log_level != "verbose":
+      self.STATUS_TIME_DELAY = 10
 
   def _Run(self, experiment):
     status = ExperimentStatus(experiment)
     experiment.Run()
     last_status_time = 0
+    last_status_string = ""
     try:
+      if experiment.log_level == "quiet":
+        self.l.LogStartDots()
       while not experiment.IsComplete():
         if last_status_time + self.STATUS_TIME_DELAY < time.time():
           last_status_time = time.time()
           border = "=============================="
-          self.l.LogOutput(border)
-          self.l.LogOutput(status.GetProgressString())
-          self.l.LogOutput(status.GetStatusString())
-          logger.GetLogger().LogOutput(border)
+          if experiment.log_level == "verbose":
+            self.l.LogOutput(border)
+            self.l.LogOutput(status.GetProgressString())
+            self.l.LogOutput(status.GetStatusString())
+            self.l.LogOutput(border)
+          else:
+            current_status_string = status.GetStatusString()
+            if (current_status_string != last_status_string):
+              self.l.LogEndDots()
+              self.l.LogOutput(border)
+              self.l.LogOutput(current_status_string)
+              self.l.LogOutput(border)
+              last_status_string = current_status_string
+            else:
+              self.l.LogAppendDot()
         time.sleep(self.THREAD_MONITOR_DELAY)
+      if experiment.log_level != "verbose":
+        self.l.LogEndDots()
     except KeyboardInterrupt:
       self._terminated = True
       self.l.LogError("Ctrl-c pressed. Cleaning up...")
diff --git a/crosperf/experiment_status.py b/crosperf/experiment_status.py
index a9ff8edb..f855ca68 100644
--- a/crosperf/experiment_status.py
+++ b/crosperf/experiment_status.py
@@ -16,6 +16,7 @@ class ExperimentStatus(object):
     self.num_total = len(self.experiment.benchmark_runs)
     self.completed = 0
     self.new_job_start_time = time.time()
+    self.log_level = experiment.log_level
 
   def _GetProgressBar(self, num_complete, num_total):
     ret = "Done: %s%%" % int(100.0 * num_complete / num_total)
@@ -96,8 +97,9 @@ class ExperimentStatus(object):
                             (key, self._GetNamesAndIterations(val)))
     result = "Thread Status:\n%s" % "\n".join(status_strings)
 
-    # Add the machine manager status.
-    result += "\n" + self.experiment.machine_manager.AsString() + "\n"
+    if self.experiment.log_level == "verbose":
+      # Add the machine manager status.
+      result += "\n" + self.experiment.machine_manager.AsString() + "\n"
 
     return result
 
@@ -107,5 +109,8 @@ class ExperimentStatus(object):
     for benchmark_run in benchmark_runs:
       t_last = benchmark_run.timeline.GetLastEventTime()
       elapsed = str(datetime.timedelta(seconds=int(t-t_last)))
-      strings.append("'{0}' {1}".format(benchmark_run.name, elapsed))
+      if self.experiment.log_level == "verbose":
+        strings.append("'{0}' {1}".format(benchmark_run.name, elapsed))
+      else:
+        strings.append("'{0}'".format(benchmark_run.name))
     return " %s (%s)" % (len(strings), ", ".join(strings))
diff --git a/crosperf/image_checksummer.py b/crosperf/image_checksummer.py
index eeb4466e..2f6694d9 100644
--- a/crosperf/image_checksummer.py
+++ b/crosperf/image_checksummer.py
@@ -11,10 +11,11 @@ from utils.file_utils import FileUtils
 
 class ImageChecksummer(object):
   class PerImageChecksummer(object):
-    def __init__(self, label):
+    def __init__(self, label, log_level):
       self._lock = threading.Lock()
       self.label = label
       self._checksum = None
+      self.log_level = log_level
 
     def Checksum(self):
       with self._lock:
@@ -26,7 +27,8 @@ class ImageChecksummer(object):
             raise Exception("Called Checksum on non-local image!")
           if self.label.chromeos_image:
             if os.path.exists(self.label.chromeos_image):
-              self._checksum = FileUtils().Md5File(self.label.chromeos_image)
+              self._checksum = FileUtils().Md5File(self.label.chromeos_image,
+                                                   log_level=self.log_level)
               logger.GetLogger().LogOutput("Computed checksum is "
                                            ": %s" % self._checksum)
           if not self._checksum:
@@ -50,13 +52,14 @@ class ImageChecksummer(object):
                                                              *args, **kwargs)
       return cls._instance
 
-  def Checksum(self, label):
+  def Checksum(self, label, log_level):
     if label.image_type != "local":
       raise Exception("Attempt to call Checksum on non-local image.")
     with self._lock:
       if label.name not in self._per_image_checksummers:
         self._per_image_checksummers[label.name] = (ImageChecksummer.
-                                                    PerImageChecksummer(label))
+                                                    PerImageChecksummer(label,
+                                                                        log_level))
       checksummer = self._per_image_checksummers[label.name]
 
     try:
diff --git a/crosperf/machine_manager.py b/crosperf/machine_manager.py
index 51e10554..0271df4c 100644
--- a/crosperf/machine_manager.py
+++ b/crosperf/machine_manager.py
@@ -24,7 +24,7 @@ CHECKSUM_FILE = "/usr/local/osimage_checksum_file"
 
 
 class CrosMachine(object):
-  def __init__(self, name, chromeos_root):
+  def __init__(self, name, chromeos_root, log_level):
     self.name = name
     self.image = None
     self.checksum = None
@@ -32,6 +32,7 @@ class CrosMachine(object):
     self.released_time = time.time()
     self.test_run = None
     self.chromeos_root = chromeos_root
+    self.log_level = log_level
     if not self.IsReachable():
       self.machine_checksum = None
       return
@@ -43,7 +44,7 @@ class CrosMachine(object):
     self.machine_id_checksum = self._GetMD5Checksum(self.machine_id)
 
   def IsReachable(self):
-    ce = command_executer.GetCommandExecuter()
+    ce = command_executer.GetCommandExecuter(log_level=self.log_level)
     command = "ls"
     ret = ce.CrosRunCommand(command,
                             machine=self.name,
@@ -86,7 +87,7 @@ class CrosMachine(object):
   def _GetMemoryInfo(self):
     #TODO yunlian: when the machine in rebooting, it will not return
     #meminfo, the assert does not catch it either
-    ce = command_executer.GetCommandExecuter()
+    ce = command_executer.GetCommandExecuter(log_level=self.log_level)
     command = "cat /proc/meminfo"
     ret, self.meminfo, _ = ce.CrosRunCommand(
         command, return_output=True,
@@ -101,7 +102,7 @@ class CrosMachine(object):
     return 0
 
   def _GetCPUInfo(self):
-    ce = command_executer.GetCommandExecuter()
+    ce = command_executer.GetCommandExecuter(log_level=self.log_level)
     command = "cat /proc/cpuinfo"
     ret, self.cpuinfo, _ = ce.CrosRunCommand(
         command, return_output=True,
@@ -125,7 +126,7 @@ class CrosMachine(object):
       return ""
 
   def _GetMachineID(self):
-    ce = command_executer.GetCommandExecuter()
+    ce = command_executer.GetCommandExecuter(log_level=self.log_level)
     command = "dump_vpd_log --full --stdout"
     ret, if_out, _ = ce.CrosRunCommand(
         command, return_output=True,
@@ -161,7 +162,7 @@ class CrosMachine(object):
 
 
 class MachineManager(object):
-  def __init__(self, chromeos_root, acquire_timeout):
+  def __init__(self, chromeos_root, acquire_timeout, log_level):
     self._lock = threading.RLock()
     self._all_machines = []
     self._machines = []
@@ -171,6 +172,7 @@ class MachineManager(object):
     self.machine_checksum = {}
     self.machine_checksum_string = {}
     self.acquire_timeout = acquire_timeout
+    self.log_level = log_level
 
     if os.path.isdir(lock_machine.Machine.LOCKS_DIR):
       self.no_lock = False
@@ -181,7 +183,7 @@ class MachineManager(object):
 
   def ImageMachine(self, machine, label):
     if label.image_type == "local":
-      checksum = ImageChecksummer().Checksum(label)
+      checksum = ImageChecksummer().Checksum(label, self.log_level)
     elif label.image_type == "trybot":
       checksum = machine._GetMD5Checksum(label.chromeos_image)
     else:
@@ -196,20 +198,34 @@ class MachineManager(object):
                            "--chromeos_root=%s" % chromeos_root,
                            "--image=%s" % label.chromeos_image,
                            "--image_args=%s" % label.image_args,
-                           "--remote=%s" % machine.name]
+                           "--remote=%s" % machine.name,
+                           "--logging_level=%s" % self.log_level]
     if label.board:
       image_chromeos_args.append("--board=%s" % label.board)
 
     # Currently can't image two machines at once.
     # So have to serialized on this lock.
-    ce = command_executer.GetCommandExecuter()
+    if self.log_level != "verbose":
+      ce = command_executer.GetCommandExecuter(log_level="average")
+    else:
+      ce = command_executer.GetCommandExecuter()
     with self.image_lock:
+      if self.log_level != "verbose":
+        logger.GetLogger().LogOutput("Pushing image onto machine.")
+        logger.GetLogger().LogOutput("CMD : python %s "
+                                 % " ".join(image_chromeos_args))
       retval = ce.RunCommand(" ".join(["python"] + image_chromeos_args))
       if retval:
         cmd ="reboot && exit"
+        if self.log_level != "verbose":
+          logger.GetLogger().LogOutput("reboot & exit.")
         ce.CrosRunCommand(cmd, machine=machine.name,
                           chromeos_root=self.chromeos_root)
         time.sleep(60)
+        if self.log_level != "verbose":
+          logger.GetLogger().LogOutput("Pushing image onto machine.")
+          logger.GetLogger().LogOutput("CMD : python %s "
+                                     % " ".join(image_chromeos_args))
         retval = ce.RunCommand(" ".join(["python"] + image_chromeos_args))
       if retval:
         raise Exception("Could not image machine: '%s'." % machine.name)
@@ -244,7 +260,7 @@ class MachineManager(object):
         locked = lock_machine.Machine(cros_machine.name).Lock(True, sys.argv[0])
       if locked:
         self._machines.append(cros_machine)
-        ce = command_executer.GetCommandExecuter()
+        ce = command_executer.GetCommandExecuter(log_level=self.log_level)
         command = "cat %s" % CHECKSUM_FILE
         ret, out, _ = ce.CrosRunCommand(
             command, return_output=True, chromeos_root=self.chromeos_root,
@@ -259,7 +275,12 @@ class MachineManager(object):
     with self._lock:
       for m in self._all_machines:
         assert m.name != machine_name, "Tried to double-add %s" % machine_name
-      cm = CrosMachine(machine_name, self.chromeos_root)
+      if self.log_level != "verbose":
+        logger.GetLogger().LogOutput("Setting up remote access to %s"
+                                   % machine_name)
+        logger.GetLogger().LogOutput("Checking machine characteristics for %s"
+                                   % machine_name)
+      cm = CrosMachine(machine_name, self.chromeos_root, self.log_level)
       if cm.machine_checksum:
         self._all_machines.append(cm)
 
@@ -278,7 +299,7 @@ class MachineManager(object):
 
   def AcquireMachine(self, chromeos_image, label):
     if label.image_type == "local":
-      image_checksum = ImageChecksummer().Checksum(label)
+      image_checksum = ImageChecksummer().Checksum(label, self.log_level)
     elif label.image_type == "trybot":
       image_checksum = hashlib.md5(chromeos_image).hexdigest()
     else:
@@ -423,7 +444,7 @@ class MachineManager(object):
 
 
 class MockCrosMachine(CrosMachine):
-  def __init__(self, name, chromeos_root):
+  def __init__(self, name, chromeos_root, log_level):
     self.name = name
     self.image = None
     self.checksum = None
@@ -434,12 +455,14 @@ class MockCrosMachine(CrosMachine):
     self.checksum_string = re.sub("\d", "", name)
     #In test, we assume "lumpy1", "lumpy2" are the same machine.
     self.machine_checksum =  self._GetMD5Checksum(self.checksum_string)
+    self.log_level = log_level
 
 
 class MockMachineManager(MachineManager):
 
-  def __init__(self, chromeos_root, acquire_timeout):
-    super(MockMachineManager, self).__init__(chromeos_root, acquire_timeout)
+  def __init__(self, chromeos_root, acquire_timeout, log_level):
+    super(MockMachineManager, self).__init__(chromeos_root, acquire_timeout,
+                                             log_level)
 
   def _TryToLockMachine(self, cros_machine):
     self._machines.append(cros_machine)
@@ -449,7 +472,7 @@ class MockMachineManager(MachineManager):
     with self._lock:
       for m in self._all_machines:
         assert m.name != machine_name, "Tried to double-add %s" % machine_name
-      cm = MockCrosMachine(machine_name, self.chromeos_root)
+      cm = MockCrosMachine(machine_name, self.chromeos_root, self.log_level)
       assert cm.machine_checksum, ("Could not find checksum for machine %s" %
                                    machine_name)
       self._all_machines.append(cm)
diff --git a/crosperf/results_cache.py b/crosperf/results_cache.py
index 2402c2ec..fcb86ae3 100644
--- a/crosperf/results_cache.py
+++ b/crosperf/results_cache.py
@@ -35,13 +35,15 @@ class Result(object):
   perf.report, etc. The key generation is handled by the ResultsCache class.
   """
 
-  def __init__(self, logger, label):
+  def __init__(self, logger, label, log_level):
     self._chromeos_root = label.chromeos_root
     self._logger = logger
-    self._ce = command_executer.GetCommandExecuter(self._logger)
+    self._ce = command_executer.GetCommandExecuter(self._logger,
+                                                   log_level=log_level)
     self._temp_dir = None
     self.label = label
     self.results_dir = None
+    self.log_level = log_level
     self.perf_data_files = []
     self.perf_report_files = []
 
@@ -386,22 +388,22 @@ class Result(object):
                       (temp_dir, cache_dir))
 
   @classmethod
-  def CreateFromRun(cls, logger, label, out, err, retval, show_all, test,
-                    suite="pyauto"):
+  def CreateFromRun(cls, logger, log_level, label, out, err, retval, show_all,
+                    test, suite="pyauto"):
     if suite == "telemetry":
       result = TelemetryResult(logger, label)
     else:
-      result = cls(logger, label)
+      result = cls(logger, label, log_level)
     result._PopulateFromRun(out, err, retval, show_all, test, suite)
     return result
 
   @classmethod
-  def CreateFromCacheHit(cls, logger, label, cache_dir, show_all, test,
-                         suite="pyauto"):
+  def CreateFromCacheHit(cls, logger, log_level, label, cache_dir,
+                         show_all, test, suite="pyauto"):
     if suite == "telemetry":
       result = TelemetryResult(logger, label)
     else:
-      result = cls(logger, label)
+      result = cls(logger, label, log_level)
     try:
       result._PopulateFromCacheDir(cache_dir, show_all, test, suite)
 
@@ -498,7 +500,8 @@ class ResultsCache(object):
 
   def Init(self, chromeos_image, chromeos_root, test_name, iteration,
            test_args, profiler_args, machine_manager, board, cache_conditions,
-           logger_to_use, label, share_users, suite, show_all_results):
+           logger_to_use, log_level, label, share_users, suite,
+           show_all_results):
     self.chromeos_image = chromeos_image
     self.chromeos_root = chromeos_root
     self.test_name = test_name
@@ -509,10 +512,12 @@ class ResultsCache(object):
     self.cache_conditions = cache_conditions
     self.machine_manager = machine_manager
     self._logger = logger_to_use
-    self._ce = command_executer.GetCommandExecuter(self._logger)
+    self._ce = command_executer.GetCommandExecuter(self._logger,
+                                                   log_level=log_level)
     self.label = label
     self.share_users = share_users
     self.suite = suite
+    self.log_level = log_level
     self.show_all = show_all_results
 
   def _GetCacheDirForRead(self):
@@ -556,7 +561,7 @@ class ResultsCache(object):
     elif self.label.image_type == "official":
       checksum = "*"
     else:
-      checksum = ImageChecksummer().Checksum(self.label)
+      checksum = ImageChecksummer().Checksum(self.label, self.log_level)
 
     if read and CacheConditions.IMAGE_PATH_MATCH not in self.cache_conditions:
       image_path_checksum = "*"
@@ -599,6 +604,7 @@ class ResultsCache(object):
 
     self._logger.LogOutput("Trying to read from cache dir: %s" % cache_dir)
     result = Result.CreateFromCacheHit(self._logger,
+                                       self.log_level,
                                        self.label,
                                        cache_dir,
                                        self.show_all,
diff --git a/crosperf/settings_factory.py b/crosperf/settings_factory.py
index 6be34816..b827cc4d 100644
--- a/crosperf/settings_factory.py
+++ b/crosperf/settings_factory.py
@@ -42,6 +42,9 @@ class BenchmarkSettings(Settings):
                             "command record or stat followed by arguments."))
     self.AddField(TextField("suite", default="pyauto",
                                description="The type of the benchmark"))
+    self.AddField(TextField("logging_level", default="verbose",
+                               description="The level of logging desired. "
+                            "Options are 'quiet', 'average', and 'verbose'."))
     self.AddField(BooleanField("use_test_that", default=True,
                                description="Whether to use the"
                                " new test_that script for running the test."))
@@ -127,6 +130,9 @@ class GlobalSettings(Settings):
                             "contains a src/scripts directory. Defaults to "
                             "the chromeos checkout which contains the "
                             "chromeos_image."))
+    self.AddField(TextField("logging_level", default="verbose",
+                               description="The level of logging desired. "
+                            "Options are 'quiet', 'average', and 'verbose'."))
     self.AddField(BooleanField("key_results_only", default=True,
                                description="Whether only show the key results"
                                "of pyautoperf"))
diff --git a/crosperf/suite_runner.py b/crosperf/suite_runner.py
index 087f64da..00e6e51e 100644
--- a/crosperf/suite_runner.py
+++ b/crosperf/suite_runner.py
@@ -43,9 +43,11 @@ class SuiteRunner(object):
   """ This defines the interface from crosperf to test script.
   """
 
-  def __init__(self, logger_to_use=None):
+  def __init__(self, logger_to_use=None, log_level="verbose"):
     self._logger = logger_to_use
-    self._ce = command_executer.GetCommandExecuter(self._logger)
+    self.log_level = log_level
+    self._ce = command_executer.GetCommandExecuter(self._logger,
+                                                   log_level=self.log_level)
     self._ct = command_executer.CommandTerminator()
 
   def Run(self, machine, label, benchmark, test_args, profiler_args):
@@ -99,6 +101,9 @@ class SuiteRunner(object):
                                       body="echo %s > $f" % highest_freq)
     change_perf_gov = BASH_FOR.format(list=CPUFREQ_DIRS + "scaling_governor",
                                       body="echo performance > $f")
+    if self.log_level == "average":
+      self._logger.LogOutput("Pinning governor execution frequencies for %s"
+                           % machine_name)
     ret = self._ce.CrosRunCommand(" && ".join(("set -e ",
                                                change_max_freq,
                                                change_min_freq,
@@ -135,6 +140,9 @@ class SuiteRunner(object):
 
     command = ("./run_remote_tests.sh --use_emerged --remote=%s %s %s" %
                (machine, options, benchmark.test_name))
+    if self.log_level != "verbose":
+      self._logger.LogOutput("Running test.")
+      self._logger.LogOutput("CMD: %s" % command)
     return self._ce.ChrootRunCommand(label.chromeos_root,
                                      command,
                                      True,
@@ -159,6 +167,9 @@ class SuiteRunner(object):
 
     command = ("%s %s %s %s" %
                (TEST_THAT_PATH, options, machine, benchmark.test_name))
+    if self.log_level != "verbose":
+      self._logger.LogOutput("Running test.")
+      self._logger.LogOutput("CMD: %s" % command)
     return self._ce.ChrootRunCommand(label.chromeos_root,
                                      command,
                                      True,
@@ -197,6 +208,9 @@ class SuiteRunner(object):
                                                 benchmark.test_name,
                                                 profiler_args,
                                                 machine))
+    if self.log_level != "verbose":
+      self._logger.LogOutput("Running test.")
+      self._logger.LogOutput("CMD: %s" % cmd)
     return self._ce.ChrootRunCommand (label.chromeos_root,
                                       cmd,
                                       return_output=True,
@@ -221,6 +235,9 @@ class SuiteRunner(object):
                             rsa_key,
                             benchmark.test_name,
                             benchmark.test_args))
+    if self.log_level != "verbose":
+      self._logger.LogOutput("Running test.")
+      self._logger.LogOutput("CMD: %s" % cmd)
     return self._ce.RunCommand(cmd, return_output=True,
                                print_to_console=False)