Clean up extreme verbosity of logs in test harness.

au_test_harness/cros_au_test_harness.py

 #!/usr/bin/python
 
 # Copyright (c) 2011 The Chromium OS Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 
 """This module runs a suite of Auto Update tests.
 
   The tests can be run on either a virtual machine or actual device depending
   on parameters given.  Specific tests can be run by invoking --test_prefix.
@@ skipping 50 matching lines @@
               ]
     # Add actual args to command.
     command.append('--image=%s' % cros_lib.ReinterpretPathForChroot(target))
     if src: command.append('--src_image=%s' %
                            cros_lib.ReinterpretPathForChroot(src))
     if options.type == 'vm': command.append('--for_vm')
     if private_key_path:
       command.append('--private_key=%s' %
                      cros_lib.ReinterpretPathForChroot(private_key_path))
 
-    return cros_lib.RunCommand(command, enter_chroot=True, print_cmd=True,
+    if src:
+      debug_message = 'delta update payload from %s to %s' % (target, src)
+    else:
+      debug_message = 'full update payload to %s' % target
+
+    if private_key_path:
+      debug_message = 'Generating a signed ' + debug_message
+    else:
+      debug_message = 'Generating an unsigned ' + debug_message
+
+    cros_lib.Info(debug_message)
+    return cros_lib.RunCommand(command, enter_chroot=True, print_cmd=False,
                                cwd=cros_lib.GetCrosUtilsPath(),
                                log_to_file=log_file, error_ok=True,
                                exit_code=True)
 
   def _ProcessGeneratorOutputs(log_files, return_codes):
     """Processes results from the log files of GenerateVMUpdate calls.
 
     Returns an array of cache entries from the log files.
     """
     return_array = []
@@ skipping 17 matching lines @@
             path_to_update_gz = match.group(1).rstrip()
             (path_to_update_dir, _, _) = path_to_update_gz.rpartition(
                 '/update.gz')
             return_array.append('/'.join(['update', path_to_update_dir]))
 
     assert len(return_array) == len(log_files), 'Return result size mismatch.'
     return return_array
 
   # Use dummy class to mock out updates that would be run as part of a test.
   test_suite = _PrepareTestSuite(options, use_dummy_worker=True)
-  test_result = unittest.TextTestRunner(verbosity=0).run(test_suite)
+  test_result = unittest.TextTestRunner(
+      stream=open(os.devnull, 'w')).run(test_suite)
   if not test_result.wasSuccessful():
     raise update_exception.UpdateException(1,
                                            'Error finding updates to generate.')
-
-  cros_lib.Info('The following delta updates are required.')
   update_ids = []
   jobs = []
   args = []
   log_files = []
   modified_images = set()
   for target, srcs in dummy_au_worker.DummyAUWorker.delta_list.items():
     modified_images.add(target)
     for src_key in srcs:
       log_file = tempfile.mktemp('GenerateVMUpdate')
       (src, _ , key) = src_key.partition('+')
       if src: modified_images.add(src)
       # TODO(sosa): Add private key as part of caching name once devserver can
       # handle it its own cache.
       update_id = dev_server_wrapper.GenerateUpdateId(target, src, key)
-      print >> sys.stderr, 'AU: %s' % update_id
       update_ids.append(update_id)
       jobs.append(_GenerateVMUpdate)
       args.append((target, src, key, log_file))
       log_files.append(log_file)
 
   # Always add the base image path.  This is only useful for non-delta updates.
   modified_images.add(options.base_image)
 
   # Add public key to all images we are using.
   if options.public_key:
     cros_lib.Info('Adding public keys to images for testing.')
     for image in modified_images:
       manager = public_key_manager.PublicKeyManager(image, options.public_key)
       manager.AddKeyToImage()
       au_test.AUTest.public_key_managers.append(manager)
 
+  cros_lib.Info('Generating updates required for this test suite in parallel.')
   error_codes = parallel_test_job.RunParallelJobs(options.jobs, jobs, args)
   results = _ProcessGeneratorOutputs(log_files, error_codes)
 
   # Build the dictionary from our id's and returned cache paths.
   cache_dictionary = {}
   for index, id in enumerate(update_ids):
     cache_dictionary[id] = results[index]
 
   return cache_dictionary
 
 
 def _RunTestsInParallel(options):
   """Runs the tests given by the options in parallel."""
   threads = []
   args = []
   test_suite = _PrepareTestSuite(options)
   for test in test_suite:
     test_name = test.id()
     test_case = unittest.TestLoader().loadTestsFromName(test_name)
-    threads.append(unittest.TextTestRunner(verbosity=2).run)
+    threads.append(unittest.TextTestRunner().run)
     args.append(test_case)
 
+  cros_lib.Info('Running tests in test suite in parallel.')
   results = parallel_test_job.RunParallelJobs(options.jobs, threads, args)
   for test_result in results:
     if not test_result.wasSuccessful():
-      cros_lib.Die('Test harness was not successful')
+      cros_lib.Die(
+          'Test harness was not successful. See logs for details. '
+          'Note:  Ignore max recursion depth errors crosbug.com/14274')
 
 
 def _CleanPreviousWork(options):
   """Cleans up previous work from the devserver cache and local image cache."""
   cros_lib.Info('Cleaning up previous work.')
   # Wipe devserver cache.
   cros_lib.RunCommandCaptureOutput(
       ['sudo', 'start_devserver', '--clear_cache', '--exit', ],
       enter_chroot=True, print_cmd=False, combine_stdout_stderr=True,
       cwd=cros_lib.GetCrosUtilsPath())
@@ skipping 80 matching lines @@
     my_server = dev_server_wrapper.DevServerWrapper(
         au_test.AUTest.test_results_root)
     my_server.start()
     try:
       if options.type == 'vm':
         _RunTestsInParallel(options)
       else:
         # TODO(sosa) - Take in a machine pool for a real test.
         # Can't run in parallel with only one remote device.
         test_suite = _PrepareTestSuite(options)
-        test_result = unittest.TextTestRunner(verbosity=2).run(test_suite)
+        test_result = unittest.TextTestRunner().run(test_suite)
         if not test_result.wasSuccessful(): cros_lib.Die('Test harness failed.')
 
     finally:
       my_server.Stop()
 
   finally:
     # Un-modify any target images we modified.  We don't need to un-modify
     # non-targets because they aren't important for archival steps.
     if options.public_key:
       cros_lib.Info('Cleaning up.  Removing keys added as part of testing.')
       target_directory = os.path.dirname(options.target_image)
       for key_manager in au_test.AUTest.public_key_managers:
         if key_manager.image_path.startswith(target_directory):
           key_manager.RemoveKeyFromImage()
 
 
 if __name__ == '__main__':
   main()