Make test run logger object universally available within a test run.

Bug=28591815

Now that the logger obj doesn't need to be explicitly passed in any
more, we could get rid of the "log" param in controller interface.

Change-Id: I8586f7eafdc45854b21523b7ab319c2e1d62de38
diff --git a/acts/framework/acts/bin/act.py b/acts/framework/acts/bin/act.py
index 8fa87d2..491bedf 100755
--- a/acts/framework/acts/bin/act.py
+++ b/acts/framework/acts/bin/act.py
@@ -192,15 +192,18 @@
         config_jsons.append(new_test_config)
     return config_jsons
 
-def _run_test(test_runner, repeat=1):
+def _run_test(parsed_config, test_identifiers, repeat=1):
     """Instantiate and runs TestRunner.
 
     This is the function to start separate processes with.
 
     Args:
-        test_runner: The test_runner instance to be executed.
+        parsed_config: A dict that is a set of configs for one TestRunner.
+        test_identifiers: A list of tuples, each identifies what test case to
+                          run on what test class.
         repeat: Number of times to iterate the specified tests.
     """
+    test_runner = _create_test_runner(parsed_config, test_identifiers)
     try:
         for i in range(repeat):
             test_runner.run()
@@ -221,21 +224,89 @@
         sys.exit(1)
     return termination_sig_handler
 
-def _run_tests_parallel(process_args):
-    print("Executing {} concurrent test runs.".format(len(process_args)))
-    results = concurrent_exec(_run_test, process_args)
+def _create_test_runner(parsed_config, test_identifiers):
+    """Instantiates one TestRunner object and register termination signal
+    handlers that properly shut down the TestRunner run.
+
+    Args:
+        parsed_config: A dict that is a set of configs for one TestRunner.
+        test_identifiers: A list of tuples, each identifies what test case to
+                          run on what test class.
+
+    Returns:
+        A TestRunner object.
+    """
+    try:
+        t = TestRunner(parsed_config, test_identifiers)
+    except:
+        print("Failed to instantiate test runner, abort.")
+        print(traceback.format_exc())
+        sys.exit(1)
+    # Register handler for termination signals.
+    handler = _gen_term_signal_handler([t])
+    signal.signal(signal.SIGTERM, handler)
+    signal.signal(signal.SIGINT, handler)
+    return t
+
+def _run_tests_parallel(parsed_configs, test_identifiers, repeat):
+    """Executes requested tests in parallel.
+
+    Each test run will be in its own process.
+
+    Args:
+        parsed_config: A list of dicts, each is a set of configs for one
+                       TestRunner.
+        test_identifiers: A list of tuples, each identifies what test case to
+                          run on what test class.
+        repeat: Number of times to iterate the specified tests.
+
+    Returns:
+        True if all test runs executed successfully, False otherwise.
+    """
+    print("Executing {} concurrent test runs.".format(len(parsed_configs)))
+    arg_list = [(c, test_identifiers, repeat) for c in parsed_configs]
+    results = []
+    with multiprocessing.Pool(processes=len(parsed_configs)) as pool:
+        # Can't use starmap for py2 compatibility. One day, one day......
+        for args in arg_list:
+            results.append(pool.apply_async(_run_test, args))
+        pool.close()
+        pool.join()
     for r in results:
         if r is False or isinstance(r, Exception):
             return False
 
-def _run_tests_sequential(process_args):
+def _run_tests_sequential(parsed_configs, test_identifiers, repeat):
+    """Executes requested tests sequentially.
+
+    Requested test runs will commence one after another according to the order
+    of their corresponding configs.
+
+    Args:
+        parsed_config: A list of dicts, each is a set of configs for one
+                       TestRunner.
+        test_identifiers: A list of tuples, each identifies what test case to
+                          run on what test class.
+        repeat: Number of times to iterate the specified tests.
+
+    Returns:
+        True if all test runs executed successfully, False otherwise.
+    """
     ok = True
-    for args in process_args:
-        if _run_test(*args) is False:
+    for c in parsed_configs:
+        if _run_test(c, test_identifiers, repeat) is False:
             ok = False
     return ok
 
 def _parse_test_file(fpath):
+    """Parses a test file that contains test specifiers.
+
+    Args:
+        fpath: A string that is the path to the test file to parse.
+
+    Returns:
+        A list of strings, each is a test specifier.
+    """
     try:
         with open(fpath, 'r') as f:
             tf = []
@@ -261,8 +332,6 @@
         metavar="Arg1 Arg2 ...",
         help=("Command-line arguments to be passed to every test case in a "
               "test run. Use with caution."))
-    parser.add_argument('-d', '--debug', action="store_true",
-        help=("Set this flag if manual debugging is required."))
     parser.add_argument('-p', '--parallel', action="store_true",
         help=("If set, tests will be executed on all testbeds in parallel. "
               "Otherwise, tests are executed iteratively testbed by testbed."))
@@ -294,30 +363,15 @@
     if not parsed_configs:
         print("Encountered error when parsing the config file, abort!")
         sys.exit(1)
+    for c in parsed_configs:
+        c[Config.ikey_cli_args.value] = args.test_args
     # Prepare args for test runs
     test_identifiers = parse_test_list(test_list)
-    test_runners = []
-    process_args = []
-    try:
-        for c in parsed_configs:
-            c[Config.ikey_cli_args.value] = args.test_args
-            t = TestRunner(c, test_identifiers)
-            test_runners.append(t)
-            process_args.append((t, repeat))
-    except:
-        print("Failed to instantiate test runner, abort.")
-        print(traceback.format_exc())
-        sys.exit(1)
-    # Register handler for term signals if in -i mode.
-    if not args.debug:
-        handler = _gen_term_signal_handler(test_runners)
-        signal.signal(signal.SIGTERM, handler)
-        signal.signal(signal.SIGINT, handler)
     # Execute test runners.
-    if args.parallel and len(process_args) > 1:
-        exec_result = _run_tests_parallel(process_args)
+    if args.parallel and len(parsed_configs) > 1:
+        exec_result = _run_tests_parallel(parsed_configs, test_identifiers, repeat)
     else:
-        exec_result = _run_tests_sequential(process_args)
+        exec_result = _run_tests_sequential(parsed_configs, test_identifiers, repeat)
     if exec_result is False:
         sys.exit(1)
     sys.exit(0)
diff --git a/acts/framework/acts/controllers/access_point.py b/acts/framework/acts/controllers/access_point.py
index 3cca2c7..ef1ef6b 100755
--- a/acts/framework/acts/controllers/access_point.py
+++ b/acts/framework/acts/controllers/access_point.py
@@ -20,7 +20,7 @@
 ACTS_CONTROLLER_CONFIG_NAME = "AP"
 ACTS_CONTROLLER_REFERENCE_NAME = "access_points"
 
-def create(configs, logger):
+def create(configs):
     results = []
     for c in configs:
         addr = c[Config.key_address.value]
diff --git a/acts/framework/acts/controllers/android_device.py b/acts/framework/acts/controllers/android_device.py
index 4ec552e..09ce88f 100644
--- a/acts/framework/acts/controllers/android_device.py
+++ b/acts/framework/acts/controllers/android_device.py
@@ -17,6 +17,7 @@
 from builtins import str
 from builtins import open
 
+import logging
 import os
 import time
 import traceback
@@ -45,7 +46,8 @@
     """Raised when something that does not exist is referenced.
     """
 
-def create(configs, logger):
+def create(configs):
+    logger = logging.getLogger()
     if not configs:
         raise AndroidDeviceError(ANDROID_DEVICE_EMPTY_CONFIG_MSG)
     elif configs == ANDROID_DEVICE_PICK_ALL_TOKEN:
diff --git a/acts/framework/acts/controllers/attenuator.py b/acts/framework/acts/controllers/attenuator.py
index cafc5b0..813ef6f 100644
--- a/acts/framework/acts/controllers/attenuator.py
+++ b/acts/framework/acts/controllers/attenuator.py
@@ -15,13 +15,14 @@
 #   limitations under the License.
 
 import importlib
+import logging
 
 from acts.keys import Config
 
 ACTS_CONTROLLER_CONFIG_NAME = "Attenuator"
 ACTS_CONTROLLER_REFERENCE_NAME = "attenuators"
 
-def create(configs, logger):
+def create(configs):
     objs = []
     for c in configs:
         attn_model = c["Model"]
@@ -43,7 +44,7 @@
                 try:
                     setattr(attn, "path", c["Paths"][i])
                 except IndexError:
-                    logger.error("No path specified for attenuator %d." % i)
+                    logging.error("No path specified for attenuator %d.", i)
                     raise
             objs.append(attn)
     return objs
diff --git a/acts/framework/acts/controllers/iperf_server.py b/acts/framework/acts/controllers/iperf_server.py
index 4db9be9..0ea80bc 100755
--- a/acts/framework/acts/controllers/iperf_server.py
+++ b/acts/framework/acts/controllers/iperf_server.py
@@ -15,6 +15,7 @@
 #   limitations under the License.
 
 import json
+import logging
 import os
 import subprocess
 
@@ -24,11 +25,11 @@
 ACTS_CONTROLLER_CONFIG_NAME = "IPerfServer"
 ACTS_CONTROLLER_REFERENCE_NAME = "iperf_servers"
 
-def create(configs, logger):
+def create(configs):
     results = []
     for c in configs:
         try:
-            results.append(IPerfServer(c, logger.log_path))
+            results.append(IPerfServer(c, logging.log_path))
         except:
             pass
     return results
diff --git a/acts/framework/acts/controllers/monsoon.py b/acts/framework/acts/controllers/monsoon.py
index 2cced90..8135bfd 100644
--- a/acts/framework/acts/controllers/monsoon.py
+++ b/acts/framework/acts/controllers/monsoon.py
@@ -22,6 +22,7 @@
 _author_ = 'kens@google.com (Ken Shirriff)'
 
 import fcntl
+import logging
 import os
 import select
 import struct
@@ -34,7 +35,6 @@
 # On ubuntu, apt-get install python3-pyserial
 import serial
 
-import acts.logger
 import acts.signals
 
 from acts import utils
@@ -43,10 +43,10 @@
 ACTS_CONTROLLER_CONFIG_NAME = "Monsoon"
 ACTS_CONTROLLER_REFERENCE_NAME = "monsoons"
 
-def create(configs, logger):
+def create(configs):
     objs = []
     for c in configs:
-        objs.append(Monsoon(serial=c, logger=logger))
+        objs.append(Monsoon(serial=c))
     return objs
 
 def destroy(objs):
@@ -589,10 +589,7 @@
     def __init__(self, *args, **kwargs):
         serial = kwargs["serial"]
         device = None
-        if "logger" in kwargs:
-            self.log = acts.logger.LoggerProxy(kwargs["logger"])
-        else:
-            self.log = acts.logger.LoggerProxy()
+        self.log = logging.getLogger()
         if "device" in kwargs:
             device = kwargs["device"]
         self.mon = MonsoonProxy(serialno=serial, device=device)
diff --git a/acts/framework/acts/controllers/native_android_device.py b/acts/framework/acts/controllers/native_android_device.py
index 4730f68..27e68d3 100644
--- a/acts/framework/acts/controllers/native_android_device.py
+++ b/acts/framework/acts/controllers/native_android_device.py
@@ -20,6 +20,7 @@
 import acts.controllers.native as native
 from subprocess import call
 
+import logging
 import time
 
 #TODO(tturney): Merge this into android device
@@ -27,7 +28,8 @@
 ACTS_CONTROLLER_CONFIG_NAME = "NativeAndroidDevice"
 ACTS_CONTROLLER_REFERENCE_NAME = "native_android_devices"
 
-def create(configs, logger):
+def create(configs):
+    logger = logging.getLogger()
     ads = get_instances(configs, logger)
     for ad in ads:
         try:
diff --git a/acts/framework/acts/controllers/sniffer.py b/acts/framework/acts/controllers/sniffer.py
index 3ec335a..1e45182 100644
--- a/acts/framework/acts/controllers/sniffer.py
+++ b/acts/framework/acts/controllers/sniffer.py
@@ -15,11 +15,12 @@
 #   limitations under the License.
 
 import importlib
+import logging
 
 ACTS_CONTROLLER_CONFIG_NAME = "Sniffer"
 ACTS_CONTROLLER_REFERENCE_NAME = "sniffers"
 
-def create(configs, logger):
+def create(configs):
     """Initializes the sniffer structures based on the JSON configuration. The
     expected keys are:
 
@@ -41,7 +42,7 @@
         module_name = "acts.controllers.sniffer_lib.{}.{}".format(sniffer_type,
                                                             sniffer_subtype)
         module = importlib.import_module(module_name)
-        objs.append(module.Sniffer(interface, logger,
+        objs.append(module.Sniffer(interface, logging.getLogger(),
                                    base_configs=base_configs))
     return objs
 
diff --git a/acts/framework/acts/logger.py b/acts/framework/acts/logger.py
index c89c4f2..82ee2c3 100755
--- a/acts/framework/acts/logger.py
+++ b/acts/framework/acts/logger.py
@@ -112,8 +112,8 @@
     """
     return _get_timestamp("%m-%d-%Y_%H-%M-%S-%f", delta)
 
-def _get_test_logger(log_path, TAG, prefix=None, filename=None):
-    """Returns a logger object used for tests.
+def _setup_test_logger(log_path, prefix=None, filename=None):
+    """Customizes the root logger for a test run.
 
     The logger object has a stream handler and a file handler. The stream
     handler logs INFO level to the terminal, the file handler logs DEBUG
@@ -121,18 +121,14 @@
 
     Args:
         log_path: Location of the log file.
-        TAG: Name of the logger's owner.
         prefix: A prefix for each log line in terminal.
         filename: Name of the log file. The default is the time the logger
-            is requested.
-
-    Returns:
-        A logger configured with one stream handler and one file handler
+                  is requested.
     """
-    log = logging.getLogger(TAG)
+    log = logging.getLogger()
     if log.handlers:
         # This logger has been requested before.
-        return log
+        return
     log.propagate = False
     log.setLevel(logging.DEBUG)
     # Log info to stream
@@ -155,10 +151,10 @@
     log.addHandler(ch)
     log.addHandler(fh)
     log.log_path = log_path
-    return log
+    logging.log_path = log_path
 
 def kill_test_logger(logger):
-    """Cleans up a test logger object created by get_test_logger.
+    """Cleans up a test logger object created by setup_test_logger.
 
     Args:
         logger: The logging object to clean up.
@@ -179,25 +175,20 @@
         os.remove(link_path)
     os.symlink(actual_path, link_path)
 
-def get_test_logger(log_path, TAG, prefix=None, filename=None):
-    """Returns a logger customized for a test run.
+def setup_test_logger(log_path, prefix=None, filename=None):
+    """Customizes the root logger for a test run.
 
     Args:
         log_path: Location of the report file.
-        TAG: Name of the logger's owner.
         prefix: A prefix for each log line in terminal.
         filename: Name of the files. The default is the time the objects
             are requested.
-
-    Returns:
-        A logger object.
     """
     if filename is None:
         filename = get_log_file_timestamp()
     create_dir(log_path)
-    logger = _get_test_logger(log_path, TAG, prefix, filename)
+    logger = _setup_test_logger(log_path, prefix, filename)
     create_latest_log_alias(log_path)
-    return logger
 
 def normalize_log_line_timestamp(log_line_timestamp):
     """Replace special characters in log line timestamp with normal characters.
diff --git a/acts/framework/acts/test_runner.py b/acts/framework/acts/test_runner.py
index bcf1706..0b1d6e9 100644
--- a/acts/framework/acts/test_runner.py
+++ b/acts/framework/acts/test_runner.py
@@ -20,6 +20,7 @@
 import copy
 import importlib
 import inspect
+import logging
 import os
 import pkgutil
 import sys
@@ -75,9 +76,8 @@
                               self.testbed_name,
                               start_time)
         self.log_path = os.path.abspath(l_path)
-        self.log = logger.get_test_logger(self.log_path,
-                                          self.id,
-                                          self.testbed_name)
+        logger.setup_test_logger(self.log_path, self.testbed_name)
+        self.log = logging.getLogger()
         self.controller_registry = {}
         self.controller_destructors = {}
         self.run_list = run_list
@@ -202,7 +202,7 @@
             # in case the controller module modifies the config internally.
             original_config = self.testbed_configs[module_config_name]
             controller_config = copy.deepcopy(original_config)
-            objects = create(controller_config, self.log)
+            objects = create(controller_config)
         except:
             self.log.exception(("Failed to initialize objects for controller "
                                 "%s, abort!"), module_config_name)
diff --git a/acts/framework/tests/acts_android_device_test.py b/acts/framework/tests/acts_android_device_test.py
index 79dd3b8..07707ef 100755
--- a/acts/framework/tests/acts_android_device_test.py
+++ b/acts/framework/tests/acts_android_device_test.py
@@ -124,7 +124,7 @@
                        new=mock_list_adb_devices)
     def test_create_with_pickup_all(self):
         pick_all_token = android_device.ANDROID_DEVICE_PICK_ALL_TOKEN
-        actual_ads = android_device.create(pick_all_token, logging)
+        actual_ads = android_device.create(pick_all_token)
         for actual, expected in zip(actual_ads, get_mock_ads(5)):
             self.assertEqual(actual.serial, expected.serial)
 
@@ -132,13 +132,13 @@
         expected_msg = android_device.ANDROID_DEVICE_EMPTY_CONFIG_MSG
         with self.assertRaisesRegexp(android_device.AndroidDeviceError,
                                      expected_msg):
-            android_device.create([], logging)
+            android_device.create([])
 
     def test_create_with_not_list_config(self):
         expected_msg = android_device.ANDROID_DEVICE_NOT_LIST_CONFIG_MSG
         with self.assertRaisesRegexp(android_device.AndroidDeviceError,
                                      expected_msg):
-            android_device.create("HAHA", logging)
+            android_device.create("HAHA")
 
     def test_get_device_success_with_serial(self):
         ads = get_mock_ads(5)
diff --git a/acts/framework/tests/mock_controller.py b/acts/framework/tests/mock_controller.py
index 3ad3d5c..229ed56 100644
--- a/acts/framework/tests/mock_controller.py
+++ b/acts/framework/tests/mock_controller.py
@@ -16,24 +16,25 @@
 
 # This is a mock third-party controller module used for unit testing ACTS.
 
+import logging
+
 ACTS_CONTROLLER_CONFIG_NAME = "MagicDevice"
 
-def create(configs, logger):
+def create(configs):
     objs = []
     for c in configs:
         if isinstance(c, dict):
             c.pop("serial")
-        objs.append(MagicDevice(c, logger))
+        objs.append(MagicDevice(c))
     return objs
 
 def destroy(objs):
     print("Destroying magic")
 
 class MagicDevice(object):
-    def __init__(self, config, log):
+    def __init__(self, config):
         self.magic = config
-        self.log = log
 
     def get_magic(self):
-        self.log.info("My magic is %s." % self.magic)
-        return self.magic
\ No newline at end of file
+        logging.info("My magic is %s.", self.magic)
+        return self.magic