Repository: google/mobly

Issue:
When failure occurs in setup class "begin_time" for skipped tests is null
End time is not null.

Can we either make them equal to each other (i.e. skipped test takes 0 time) or both null?

Discussion:
dthkao: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-KpuoMgbdJ67hzZXQmjJ:b-bse92z) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
> ```Python
>                 test_record = records.TestResultRecord(test_name, self.TAG)
>                 test_record.test_skip(exception)
>                 # Set the begin and end time to None as the test never started.
> ```

What happens to skips outside of an abort_class?

Why not fix in either TestResultRecord.test_skip() or TestResultRecord._end_test()?

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->

xpconanfan: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-Kpuq9cA9XCP9bS_hW7z:beu1ilq) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
<details><summary><i>Previously, dthkao (David T.H. Kao) wrote…</i></summary><blockquote>

What happens to skips outside of an abort_class?

Why not fix in either TestResultRecord.test_skip() or TestResultRecord._end_test()?


</blockquote></details>

bc they are different behaviors.
`test_skip` is used for in-test skipping, in which case both timestamps are not None

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->

dthkao: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-KpvAxuvuSpjyIcjIO4b:bn6ug98) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
<details><summary><i>Previously, xpconanfan (Ang Li) wrote…</i></summary><blockquote>

bc they are different behaviors.
`test_skip` is used for in-test skipping, in which case both timestamps are not None
</blockquote></details>

It seems odd to have the same type of result (SKIP) have different behavior due to the cause of the skip.

How about instead of setting them to NONE here, set them to the same value so that a computed duration will be zero?

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->

xpconanfan: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-KpvGc2ymMcCwT-TOH9S:bqcsjx) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
<details><summary><i>Previously, dthkao (David T.H. Kao) wrote…</i></summary><blockquote>

It seems odd to have the same type of result (SKIP) have different behavior due to the cause of the skip.

How about instead of setting them to NONE here, set them to the same value so that a computed duration will be zero?
</blockquote></details>

It makes sense because when setup skips, the test wouldn't even start, so start and end time are undefined.
In other cases, the skip happens after the test starts, so the test actually has a start and end time:

```
def test_a(self):
  ...
  asserts.skip
  ...
```

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->

dthkao: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-KpvPCHDATRNW9cEsIY5:b-16javx) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
<details><summary><i>Previously, xpconanfan (Ang Li) wrote…</i></summary><blockquote>

It makes sense because when setup skips, the test wouldn't even start, so start and end time are undefined.
In other cases, the skip happens after the test starts, so the test actually has a start and end time:

```
def test_a(self):
  ...
  asserts.skip
  ...
```
</blockquote></details>

But, it's inconsistent behavior and anyone looking at TestResultRecord.test_skip()  would fairly assume that there would at least be a non-null value for test end time (and it's not a stretch to assume that if there is a non-null end there is a non-null start).

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->

xpconanfan: 



Review status: 0 of 2 files reviewed at latest revision, 1 unresolved discussion.

---

*[mobly/base_test.py, line 506 at r1](https://reviewable.io:443/reviews/google/mobly/269#-KpuoMgbdJ67hzZXQmjI:-KpvQ5bBqTsoktINZRoL:bt56qfy) ([raw file](https://github.com/google/mobly/blob/499531fe09c3b66b7b639f3a8d9ff5c1017c6083/mobly/base_test.py#L506)):*
<details><summary><i>Previously, dthkao (David T.H. Kao) wrote…</i></summary><blockquote>

But, it's inconsistent behavior and anyone looking at TestResultRecord.test_skip()  would fairly assume that there would at least be a non-null value for test end time (and it's not a stretch to assume that if there is a non-null end there is a non-null start).
</blockquote></details>

it's not supposed to be consistent because in one case the test execution started, in the other case the test execution never started.

How do you suggest we differentiate these two cases?

---


*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/269)*
<!-- Sent from Reviewable.io -->


Patch:
diff --git a/mobly/config_parser.py b/mobly/config_parser.py
index 094777a..9d84a3a 100644
--- a/mobly/config_parser.py
+++ b/mobly/config_parser.py
@@ -37,8 +37,8 @@ def _validate_test_config(test_config):
     """
     required_key = keys.Config.key_testbed.value
     if required_key not in test_config:
-        raise MoblyConfigError('Required key %s missing in test config.' %
-                               required_key)
+        raise MoblyConfigError(
+            'Required key %s missing in test config.' % required_key)
 
 
 def _validate_testbed_name(name):
@@ -109,8 +109,8 @@ def load_test_config_file(test_config_path, tb_filters=None):
         if len(tbs) != len(tb_filters):
             raise MoblyConfigError(
                 'Expect to find %d test bed configs, found %d. Check if'
-                ' you have the correct test bed names.' %
-                (len(tb_filters), len(tbs)))
+                ' you have the correct test bed names.' % (len(tb_filters),
+                                                           len(tbs)))
         configs[keys.Config.key_testbed.value] = tbs
     mobly_params = configs.get(keys.Config.key_mobly_params.value, {})
     # Decide log path.
@@ -166,6 +166,8 @@ class TestRunConfig(object):
         user_params: dict, all the parameters to be consumed by the test logic.
         register_controller: func, used by test classes to register controller
                              modules.
+        summary_writer: records.TestSummaryWriter, used to write elements to
+                        the test result summary file.
     """
 
     def __init__(self):
@@ -174,6 +176,7 @@ class TestRunConfig(object):
         self.controller_configs = None
         self.user_params = None
         self.register_controller = None
+        self.summary_writer = None
 
     def copy(self):
         """Returns a deep copy of the current config.
diff --git a/mobly/controllers/android_device.py b/mobly/controllers/android_device.py
index 3af1040..6b37d70 100644
--- a/mobly/controllers/android_device.py
+++ b/mobly/controllers/android_device.py
@@ -688,7 +688,6 @@ class AndroidDevice(object):
         """Starts the snippet apk with the given package name and connects.
 
         Examples:
-            >>> ad = AndroidDevice()
             >>> ad.load_snippet(
                     name='maps', package='com.google.maps.snippets')
             >>> ad.maps.activateZoom('3')
diff --git a/mobly/controllers/android_device_lib/callback_handler.py b/mobly/controllers/android_device_lib/callback_handler.py
index 1ab67d8..1b0a461 100644
--- a/mobly/controllers/android_device_lib/callback_handler.py
+++ b/mobly/controllers/android_device_lib/callback_handler.py
@@ -60,6 +60,10 @@ class CallbackHandler(object):
         self.ret_value = ret_value
         self._method_name = method_name
 
+    @property
+    def callback_id(self):
+        return self._id
+
     def waitAndGet(self, event_name, timeout=DEFAULT_TIMEOUT):
         """Blocks until an event of the specified name has been received and
         return the event, or timeout.
diff --git a/mobly/controllers/android_device_lib/snippet_client.py b/mobly/controllers/android_device_lib/snippet_client.py
index f7f473b..0a6d462 100644
--- a/mobly/controllers/android_device_lib/snippet_client.py
+++ b/mobly/controllers/android_device_lib/snippet_client.py
@@ -23,12 +23,21 @@ from mobly.controllers.android_device_lib import jsonrpc_client_base
 _INSTRUMENTATION_RUNNER_PACKAGE = (
     'com.google.android.mobly.snippet.SnippetRunner')
 
-# TODO(adorokhine): delete this in Mobly 1.6 when snippet v0 support is removed.
-_LAUNCH_CMD_V0 = ('%s am instrument -w -e action start -e port %s %s/' +
-                  _INSTRUMENTATION_RUNNER_PACKAGE)
-
-_LAUNCH_CMD_V1 = (
-    '%s am instrument -w -e action start %s/' + _INSTRUMENTATION_RUNNER_PACKAGE)
+# Major version of the launch and communication protocol being used by this
+# client.
+# Incrementing this means that compatibility with clients using the older
+# version is broken. Avoid breaking compatibility unless there is no other
+# choice.
+_PROTOCOL_MAJOR_VERSION = 1
+
+# Minor version of the launch and communication protocol.
+# Increment this when new features are added to the launch and communication
+# protocol that are backwards compatible with the old protocol and don't break
+# existing clients.
+_PROTOCOL_MINOR_VERSION = 0
+
+_LAUNCH_CMD = ('%s am instrument -w -e action start %s/' +
+               _INSTRUMENTATION_RUNNER_PACKAGE)
 
 _STOP_CMD = (
     'am instrument -w -e action stop %s/' + _INSTRUMENTATION_RUNNER_PACKAGE)
@@ -45,10 +54,6 @@ _SETSID_COMMAND = 'setsid'
 
 _NOHUP_COMMAND = 'nohup'
 
-# Maximum time to wait for a v0 snippet to start on the device (10 minutes).
-# TODO(adorokhine): delete this in Mobly 1.6 when snippet v0 support is removed.
-_APP_START_WAIT_TIME_V0 = 10 * 60
-
 
 class Error(Exception):
     pass
@@ -63,9 +68,6 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
 
     See superclass documentation for a list of public attributes.
 
-    It currently supports both v0 and v1 snippet launch protocols, although
-    support for v0 will be removed in a future version.
-
     For a description of the launch protocols, see the documentation in
     mobly-snippet-lib, SnippetRunner.java.
     """
@@ -83,59 +85,42 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
         self.package = package
         self._adb = adb_proxy
         self._proc = None
-        self._launch_version = 'v1'
 
     def start_app_and_connect(self):
         """Overrides superclass. Launches a snippet app and connects to it."""
         self._check_app_installed()
 
         persists_shell_cmd = self._get_persist_command()
-        # Try launching the app with the v1 protocol. If that fails, fall back
-        # to v0 for compatibility. Use info here so people know exactly what's
-        # happening here, which is helpful since they need to create their own
-        # instrumentations and manifest.
-        self.log.info('Launching snippet apk %s with protocol v1',
-                      self.package)
-        cmd = _LAUNCH_CMD_V1 % (persists_shell_cmd, self.package)
+        # Use info here so people can follow along with the snippet startup
+        # process. Starting snippets can be slow, especially if there are
+        # multiple, and this avoids the perception that the framework is hanging
+        # for a long time doing nothing.
+        self.log.info('Launching snippet apk %s with protocol %d.%d',
+                      self.package, _PROTOCOL_MAJOR_VERSION,
+                      _PROTOCOL_MINOR_VERSION)
+        cmd = _LAUNCH_CMD % (persists_shell_cmd, self.package)
         start_time = time.time()
         self._proc = self._do_start_app(cmd)
 
-        # "Instrumentation crashed" could be due to several reasons, eg
-        # exception thrown during startup or just a launch protocol 0 snippet
-        # dying because it needs the port flag. Sadly we have no way to tell so
-        # just warn and retry as v0.
-        # TODO(adorokhine): delete this in Mobly 1.6 when snippet v0 support is
-        # removed.
+        # Check protocol version and get the device port
+        line = self._read_protocol_line()
+        match = re.match('^SNIPPET START, PROTOCOL ([0-9]+) ([0-9]+)$', line)
+        if not match or match.group(1) != '1':
+            raise ProtocolVersionError(line)
+
         line = self._read_protocol_line()
+        match = re.match('^SNIPPET SERVING, PORT ([0-9]+)$', line)
+        if not match:
+            raise ProtocolVersionError(line)
+        self.device_port = int(match.group(1))
+
         # Forward the device port to a new host port, and connect to that port
         self.host_port = utils.get_available_host_port()
-        if line in ('INSTRUMENTATION_RESULT: shortMsg=Process crashed.',
-                    'INSTRUMENTATION_RESULT: shortMsg='
-                    'java.lang.IllegalArgumentException'):
-            self.log.warning('Snippet %s crashed on startup. This might be an '
-                             'actual error or a snippet using deprecated v0 '
-                             'start protocol. Retrying as a v0 snippet.',
-                             self.package)
-            # Reuse the host port as the device port in v0 snippet. This isn't
-            # safe in general, but the protocol is deprecated.
-            self.device_port = self.host_port
-            cmd = _LAUNCH_CMD_V0 % (persists_shell_cmd, self.device_port, self.package)
-            self._proc = self._do_start_app(cmd)
-            self._connect_to_v0()
-            self._launch_version = 'v0'
-        else:
-            # Check protocol version and get the device port
-            match = re.match('^SNIPPET START, PROTOCOL ([0-9]+) ([0-9]+)$',
-                             line)
-            if not match or match.group(1) != '1':
-                raise ProtocolVersionError(line)
-
-            line = self._read_protocol_line()
-            match = re.match('^SNIPPET SERVING, PORT ([0-9]+)$', line)
-            if not match:
-                raise ProtocolVersionError(line)
-            self.device_port = int(match.group(1))
-            self._connect_to_v1()
+        self._adb.forward(
+            ['tcp:%d' % self.host_port, 'tcp:%d' % self.device_port])
+        self.connect()
+
+        # Yaaay! We're done!
         self.log.debug('Snippet %s started after %.1fs on host port %s',
                        self.package, time.time() - start_time, self.host_port)
 
@@ -156,17 +141,16 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
             AppRestoreConnectionError: When the app was not able to be started.
         """
         self.host_port = port or utils.get_available_host_port()
+        self._adb.forward(
+            ['tcp:%d' % self.host_port, 'tcp:%d' % self.device_port])
         try:
-            if self._launch_version == 'v0':
-                self._connect_to_v0()
-            else:
-                self._connect_to_v1()
+            self.connect()
         except:
             # Failed to connect to app, something went wrong.
             raise jsonrpc_client_base.AppRestoreConnectionError(
                 ('Failed to restore app connection for %s at host port %s, '
-                 'device port %s'),
-                self.package, self.host_port, self.device_port)
+                 'device port %s'), self.package, self.host_port,
+                self.device_port)
 
         # Because the previous connection was lost, update self._proc
         self._proc = None
@@ -246,34 +230,6 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
         adb_cmd += ['shell', launch_cmd]
         return utils.start_standing_subprocess(adb_cmd, shell=False)
 
-    # TODO(adorokhine): delete this in Mobly 1.6 when snippet v0 support is
-    # removed.
-    def _connect_to_v0(self):
-        self._adb.forward(
-            ['tcp:%d' % self.host_port,
-             'tcp:%d' % self.device_port])
-        start_time = time.time()
-        expiration_time = start_time + _APP_START_WAIT_TIME_V0
-        while time.time() < expiration_time:
-            self.log.debug('Attempting to start %s.', self.package)
-            try:
-                self.connect()
-                return
-            except:
-                self.log.debug(
-                    'v0 snippet %s is not yet running, retrying',
-                    self.package,
-                    exc_info=True)
-            time.sleep(1)
-        raise jsonrpc_client_base.AppStartError(
-            '%s failed to start on %s.' % (self.package, self._adb.serial))
-
-    def _connect_to_v1(self):
-        self._adb.forward(
-            ['tcp:%d' % self.host_port,
-             'tcp:%d' % self.device_port])
-        self.connect()
-
     def _read_protocol_line(self):
         """Reads the next line of instrumentation output relevant to snippets.
 
@@ -309,12 +265,14 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
         """Check availability and return path of command if available."""
         for command in [_SETSID_COMMAND, _NOHUP_COMMAND]:
             try:
-                if command in self._adb.shell('which %s' % command):
+                if command in self._adb.shell(['which',
+                                               command]).decode('utf-8'):
                     return command
             except adb.AdbError:
                 continue
-        self.log.warning('No %s and %s commands available to launch instrument '
-                         'persistently, tests that depend on UiAutomator and '
-                         'at the same time performs USB disconnection may fail',
-                         _SETSID_COMMAND, _NOHUP_COMMAND)
+        self.log.warning(
+            'No %s and %s commands available to launch instrument '
+            'persistently, tests that depend on UiAutomator and '
+            'at the same time performs USB disconnection may fail',
+            _SETSID_COMMAND, _NOHUP_COMMAND)
         return ''
diff --git a/mobly/logger.py b/mobly/logger.py
index 1bd2eb4..de90d6a 100644
--- a/mobly/logger.py
+++ b/mobly/logger.py
@@ -20,6 +20,7 @@ import os
 import re
 import sys
 
+from mobly import records
 from mobly import utils
 
 log_line_format = '%(asctime)s.%(msecs).03d %(levelname)s %(message)s'
@@ -162,11 +163,24 @@ def _setup_test_logger(log_path, prefix=None, filename=None):
     if filename is None:
         filename = get_log_file_timestamp()
         utils.create_dir(log_path)
+    # TODO(#270): Deprecate `test_run_details.txt` when we remove old output
+    # format support.
     fh = logging.FileHandler(os.path.join(log_path, 'test_run_details.txt'))
     fh.setFormatter(f_formatter)
     fh.setLevel(logging.DEBUG)
-    log.addHandler(ch)
     log.addHandler(fh)
+    # Write logger output to files
+    fh_info = logging.FileHandler(
+        os.path.join(log_path, records.OUTPUT_FILE_INFO_LOG))
+    fh_info.setFormatter(f_formatter)
+    fh_info.setLevel(logging.INFO)
+    fh_debug = logging.FileHandler(
+        os.path.join(log_path, records.OUTPUT_FILE_DEBUG_LOG))
+    fh_debug.setFormatter(f_formatter)
+    fh_debug.setLevel(logging.DEBUG)
+    log.addHandler(ch)
+    log.addHandler(fh_info)
+    log.addHandler(fh_debug)
     log.log_path = log_path
     logging.log_path = log_path
 
@@ -224,4 +238,3 @@ def normalize_log_line_timestamp(log_line_timestamp):
     norm_tp = log_line_timestamp.replace(' ', '_')
     norm_tp = norm_tp.replace(':', '-')
     return norm_tp
-
diff --git a/mobly/records.py b/mobly/records.py
index 0b67c9d..62f130b 100644
--- a/mobly/records.py
+++ b/mobly/records.py
@@ -11,19 +11,96 @@
 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 # See the License for the specific language governing permissions and
 # limitations under the License.
-"""This module is where all the record definitions and record containers live.
+"""This module has classes for test result collection, and test result output.
 """
 
 import itertools
+import copy
+import enum
 import json
 import logging
 import pprint
 import sys
 import traceback
+import yaml
 
 from mobly import signals
 from mobly import utils
 
+# File names for the output files.
+OUTPUT_FILE_INFO_LOG = 'test_log.INFO'
+OUTPUT_FILE_DEBUG_LOG = 'test_log.DEBUG'
+OUTPUT_FILE_SUMMARY = 'test_summary.yaml'
+
+
+class TestSummaryEntryType(enum.Enum):
+    """Constants used to identify the type of entries in test summary file.
+
+    Test summary file contains multiple yaml documents. In order to parse this
+    file efficiently, the write adds the type of each entry when it writes the
+    entry to the file.
+
+    The idea is similar to how `TestResult.json_str` categorizes different
+    sections of a `TestResult` object in the serialized format.
+    """
+    # A list of all the tests requested for a test run.
+    # This is dumped at the beginning of a summary file so we know what was
+    # requested in case the test is interrupted and the final summary is not.
+    # created.
+    TEST_NAME_LIST = 'TestNameList'
+    # Records of test results.
+    RECORD = 'Record'
+    # A summary of the test run stats, like how many test failed.
+    SUMMARY = 'Summary'
+    # Information on the controllers used in the test.
+    CONTROLLER_INFO = 'ControllerInfo'
+
+
+class Error(Exception):
+    """Raised for errors in records."""
+
+
+class TestSummaryWriter(object):
+    """Writer for the test result summary file of a test run.
+
+    For each test run, a writer is created to stream test results to the
+    summary file on disk.
+
+    The serialization and writing of the `TestResult` object is intentionally
+    kept out of `TestResult` class and put in this class. Because `TestResult`
+    can be operated on by suites, like `+` operation, and it is difficult to
+    guarantee the consistency between `TestResult` in memory and the files on
+    disk. Also, this separation makes it easier to provide a more generic way
+    for users to consume the test summary, like via a database instead of a
+    file.
+    """
+
+    def __init__(self, path):
+        self._path = path
+
+    def dump(self, content, entry_type):
+        """Dumps a dictionary as a yaml document to the summary file.
+
+        Each call to this method dumps a separate yaml document to the same
+        summary file associated with a test run.
+
+        The content of the dumped dictionary has an extra field `TYPE` that
+        specifies the type of each yaml document, which is the flag for parsers
+        to identify each document.
+
+        Args:
+            content: dictionary, the content to serialize and write.
+            entry_type: a member of enum TestSummaryEntryType.
+
+        Raises:
+            recoreds.Error is raised if an invalid entry type is passed in.
+        """
+        new_content = copy.deepcopy(content)
+        new_content['Type'] = entry_type.value
+        # Use safe_dump here to avoid language-specific tags in final output.
+        with open(self._path, 'a') as f:
+            yaml.safe_dump(new_content, f, explicit_start=True, indent=4)
+
 
 class TestResultEnums(object):
     """Enums used for TestResultRecord class.
@@ -89,7 +166,8 @@ class TestResultRecord(object):
                 be any exception instance or of any subclass of
                 mobly.signals.TestSignal.
         """
-        self.end_time = utils.get_current_epoch_time()
+        if self.begin_time is not None:
+            self.end_time = utils.get_current_epoch_time()
         self.result = result
         if self.extra_errors:
             self.result = TestResultEnums.TEST_RESULT_ERROR
@@ -188,6 +266,8 @@ class TestResultRecord(object):
     def json_str(self):
         """Converts this test record to a string in json format.
 
+        TODO(#270): Deprecate with old output format.
+
         Format of the json string is:
             {
                 'Test Name': <test name>,
@@ -251,7 +331,7 @@ class TestResult(object):
                 # '+' operator for TestResult is only valid when multiple
                 # TestResult objs were created in the same test run, which means
                 # the controller info would be the same across all of them.
-                # TODO(angli): have a better way to validate this situation.
+                # TODO(xpconanfan): have a better way to validate this situation.
                 setattr(sum_result, name, l_value)
         return sum_result
 
@@ -276,9 +356,9 @@ class TestResult(object):
 
     def add_controller_info(self, name, info):
         try:
-            json.dumps(info)
+            yaml.dump(info)
         except TypeError:
-            logging.warning('Controller info for %s is not JSON serializable!'
+            logging.warning('Controller info for %s is not YAML serializable!'
                             ' Coercing it to string.' % name)
             self.controller_info[name] = str(info)
             return
@@ -323,6 +403,8 @@ class TestResult(object):
     def json_str(self):
         """Converts this test result to a string in json format.
 
+        TODO(#270): Deprecate with old output format.
+
         Format of the json string is:
             {
                 'Results': [
@@ -345,6 +427,17 @@ class TestResult(object):
         json_str = json.dumps(d, indent=4, sort_keys=True)
         return json_str
 
+    def requested_test_names_dict(self):
+        """Gets the requested test names of a test run in a dict format.
+
+        Note a test can be requested multiple times, so there can be duplicated
+        values
+
+        Returns:
+            A dict with a key and the list of strings.
+        """
+        return {'Requested Tests': copy.deepcopy(self.requested)}
+
     def summary_str(self):
         """Gets a string that summarizes the stats of this test result.
 
diff --git a/mobly/utils.py b/mobly/utils.py
index 6960651..05371b2 100644
--- a/mobly/utils.py
+++ b/mobly/utils.py
@@ -273,29 +273,13 @@ def concurrent_exec(func, param_list):
             try:
                 return_vals.append(future.result())
             except Exception as exc:
-                print("{} generated an exception: {}".format(
+                logging.exception("{} generated an exception: {}".format(
                     params, traceback.format_exc()))
                 return_vals.append(exc)
         return return_vals
 
 
-def _assert_subprocess_running(proc):
-    """Checks if a subprocess has terminated on its own.
-
-    Args:
-        proc: A subprocess returned by subprocess.Popen.
-
-    Raises:
-        Error is raised if the subprocess has stopped.
-    """
-    ret = proc.poll()
-    if ret is not None:
-        out, err = proc.communicate()
-        raise Error("Process %d has terminated. ret: %d, stderr: %s,"
-                    " stdout: %s" % (proc.pid, ret, err, out))
-
-
-def start_standing_subprocess(cmd, check_health_delay=0, shell=False):
+def start_standing_subprocess(cmd, shell=False):
     """Starts a long-running subprocess.
 
     This is not a blocking call and the subprocess started by it should be
@@ -304,36 +288,27 @@ def start_standing_subprocess(cmd, check_health_delay=0, shell=False):
     For short-running commands, you should use subprocess.check_call, which
     blocks.
 
-    You can specify a health check after the subprocess is started to make sure
-    it did not stop prematurely.
-
     Args:
         cmd: string, the command to start the subprocess with.
-        check_health_delay: float, the number of seconds to wait after the
-                            subprocess starts to check its health. Default is 0,
-                            which means no check.
         shell: bool, True to run this command through the system shell,
             False to invoke it directly. See subprocess.Proc() docs.
 
     Returns:
         The subprocess that was started.
     """
-    logging.debug('Start standing subprocess with cmd: %s', cmd)
+    logging.debug('Starting standing subprocess with: %s', cmd)
     proc = subprocess.Popen(
         cmd,
         stdin=subprocess.PIPE,
         stdout=subprocess.PIPE,
         stderr=subprocess.PIPE,
         shell=shell)
-    logging.debug('Start standing subprocess with cmd: %s', cmd)
     # Leaving stdin open causes problems for input, e.g. breaking the
     # code.inspect() shell (http://stackoverflow.com/a/25512460/1612937), so
     # explicitly close it assuming it is not needed for standing subprocesses.
     proc.stdin.close()
     proc.stdin = None
-    if check_health_delay > 0:
-        time.sleep(check_health_delay)
-        _assert_subprocess_running(proc)
+    logging.debug('Started standing subprocess %d', proc.pid)
     return proc
 
 
@@ -352,10 +327,9 @@ def stop_standing_subprocess(proc, kill_signal=signal.SIGTERM):
         Error: if the subprocess could not be stopped.
     """
     pid = proc.pid
-    logging.debug('Stop standing subprocess %d', pid)
-    _assert_subprocess_running(proc)
+    logging.debug('Stopping standing subprocess %d', pid)
     process = psutil.Process(pid)
-    success = True
+    failed = []
     try:
         children = process.children(recursive=True)
     except AttributeError:
@@ -365,18 +339,25 @@ def stop_standing_subprocess(proc, kill_signal=signal.SIGTERM):
         try:
             child.kill()
             child.wait(timeout=10)
+        except psutil.NoSuchProcess:
+            # Ignore if the child process has already terminated.
+            pass
         except:
-            success = False
+            failed.append(child.pid)
             logging.exception('Failed to kill standing subprocess %d',
                               child.pid)
     try:
         process.kill()
         process.wait(timeout=10)
+    except psutil.NoSuchProcess:
+        # Ignore if the process has already terminated.
+        pass
     except:
-        success = False
+        failed.append(pid)
         logging.exception('Failed to kill standing subprocess %d', pid)
-    if not success:
-        raise Error('Some standing subprocess failed to die')
+    if failed:
+        raise Error('Failed to kill standing subprocesses: %s' % failed)
+    logging.debug('Stopped standing subprocess %d', pid)
 
 
 def wait_for_standing_subprocess(proc, timeout=None):


Test patch:
diff --git a/mobly/base_test.py b/mobly/base_test.py
index 7353afd..53042a6 100644
--- a/mobly/base_test.py
+++ b/mobly/base_test.py
@@ -87,6 +87,7 @@ class BaseTestClass(object):
         self.user_params = configs.user_params
         self.register_controller = configs.register_controller
         self.results = records.TestResult()
+        self.summary_writer = configs.summary_writer
         self.current_test_name = None
         self._generated_test_table = collections.OrderedDict()
 
@@ -186,12 +187,6 @@ class BaseTestClass(object):
         called.
         """
         self.current_test_name = test_name
-        try:
-            # Write test start token to adb log if android device is attached.
-            for ad in self.android_devices:
-                ad.sl4a.logV('%s BEGIN %s' % (TEST_CASE_TOKEN, test_name))
-        except:
-            pass
         self.setup_test()
 
     def setup_test(self):
@@ -207,16 +202,7 @@ class BaseTestClass(object):
         """Proxy function to guarantee the base implementation of teardown_test
         is called.
         """
-        try:
-            # Write test end token to adb log if android device is attached.
-            for ad in self.android_devices:
-                ad.sl4a.logV('%s END %s' % (TEST_CASE_TOKEN, test_name))
-        except:
-            pass
-        try:
-            self.teardown_test()
-        finally:
-            self.current_test_name = None
+        self.teardown_test()
 
     def teardown_test(self):
         """Teardown function that will be called every time a test method has
@@ -383,6 +369,9 @@ class BaseTestClass(object):
             elif tr_record.result == records.TestResultEnums.TEST_RESULT_SKIP:
                 self._exec_procedure_func(self._on_skip, tr_record)
             self.results.add_record(tr_record)
+            self.summary_writer.dump(tr_record.to_dict(),
+                                     records.TestSummaryEntryType.RECORD)
+            self.current_test_name = None
 
     def _assert_function_name_in_stack(self, expected_func_name):
         """Asserts that the current stack contains the given function name."""
@@ -504,6 +493,8 @@ class BaseTestClass(object):
                 test_record = records.TestResultRecord(test_name, self.TAG)
                 test_record.test_skip(exception)
                 self.results.add_record(test_record)
+                self.summary_writer.dump(test_record.to_dict(),
+                                         records.TestSummaryEntryType.RECORD)
 
     def run(self, test_names=None):
         """Runs tests within a test class.
@@ -534,6 +525,8 @@ class BaseTestClass(object):
             class_record.test_begin()
             class_record.test_error(e)
             self.results.add_class_error(class_record)
+            self.summary_writer.dump(class_record.to_dict(),
+                                     records.TestSummaryEntryType.RECORD)
             return self.results
         logging.info('==========> %s <==========', self.TAG)
         # Devise the actual test methods to run in the test class.
@@ -545,6 +538,8 @@ class BaseTestClass(object):
                 # No test method specified by user, execute all in test class.
                 test_names = self._get_all_test_names()
         self.results.requested = test_names
+        self.summary_writer.dump(self.results.requested_test_names_dict(),
+                                 records.TestSummaryEntryType.TEST_NAME_LIST)
         tests = self._get_test_methods(test_names)
         # Setup for the class.
         try:
@@ -565,6 +560,8 @@ class BaseTestClass(object):
             class_record.test_error(e)
             self._exec_procedure_func(self._on_fail, class_record)
             self.results.add_class_error(class_record)
+            self.summary_writer.dump(class_record.to_dict(),
+                                     records.TestSummaryEntryType.RECORD)
             self._skip_remaining_tests(e)
             self._safe_exec_func(self.teardown_class)
             return self.results
diff --git a/mobly/test_runner.py b/mobly/test_runner.py
index 5ae2767..49e6b45 100644
--- a/mobly/test_runner.py
+++ b/mobly/test_runner.py
@@ -80,7 +80,7 @@ def main(argv=None):
         help='Specify which test beds to run tests on.')
     if not argv:
         argv = sys.argv[1:]
-    args = parser.parse_args(argv)
+    args = parser.parse_known_args(argv)[0]
     # Load test config file.
     test_configs = config_parser.load_test_config_file(args.config[0],
                                                        args.test_bed)
@@ -158,7 +158,7 @@ def verify_controller_module(module):
 
         def get_info(objects):
             [Optional] Gets info from the controller objects used in a test
-            run. The info will be included in test_result_summary.json under
+            run. The info will be included in test_summary.yaml under
             the key 'ControllerInfo'. Such information could include unique
             ID, version, or anything that could be useful for describing the
             test bed and debugging.
@@ -262,9 +262,7 @@ class TestRunner(object):
                 (self._test_bed_name, config.test_bed_name))
         self._test_run_infos.append(
             TestRunner._TestRunInfo(
-                config=config,
-                test_class=test_class,
-                tests=tests))
+                config=config, test_class=test_class, tests=tests))
 
     def _run_test_class(self, config, test_class, tests=None):
         """Instantiates and executes a test class.
@@ -300,6 +298,8 @@ class TestRunner(object):
             raise Error('No tests to execute.')
         start_time = logger.get_log_file_timestamp()
         log_path = os.path.join(self._log_dir, self._test_bed_name, start_time)
+        summary_writer = records.TestSummaryWriter(
+            os.path.join(log_path, records.OUTPUT_FILE_SUMMARY))
         logger.setup_test_logger(log_path, self._test_bed_name)
         try:
             for test_run_info in self._test_run_infos:
@@ -308,7 +308,7 @@ class TestRunner(object):
                 test_config.log_path = log_path
                 test_config.register_controller = functools.partial(
                     self._register_controller, test_config)
-
+                test_config.summary_writer = summary_writer
                 try:
                     self._run_test_class(test_config, test_run_info.test_class,
                                          test_run_info.tests)
@@ -319,6 +319,11 @@ class TestRunner(object):
                 finally:
                     self._unregister_controllers()
         finally:
+            # Write controller info and summary to summary file.
+            summary_writer.dump(self.results.controller_info,
+                                records.TestSummaryEntryType.CONTROLLER_INFO)
+            summary_writer.dump(self.results.summary_dict(),
+                                records.TestSummaryEntryType.SUMMARY)
             # Stop and show summary.
             msg = '\nSummary for test run %s@%s: %s\n' % (
                 self._test_bed_name, start_time, self.results.summary_str())
@@ -438,7 +443,7 @@ class TestRunner(object):
     def _write_results_json_str(self, log_path):
         """Writes out a json file with the test result info for easy parsing.
 
-        TODO(angli): This should be replaced by standard log record mechanism.
+        TODO(#270): Deprecate with old output format.
         """
         path = os.path.join(log_path, 'test_run_summary.json')
         with open(path, 'w') as f:
diff --git a/tests/mobly/base_test_test.py b/tests/mobly/base_test_test.py
index 35c29f2..fd55650 100755
--- a/tests/mobly/base_test_test.py
+++ b/tests/mobly/base_test_test.py
@@ -40,6 +40,7 @@ class SomeError(Exception):
 class BaseTestTest(unittest.TestCase):
     def setUp(self):
         self.mock_test_cls_configs = config_parser.TestRunConfig()
+        self.mock_test_cls_configs.summary_writer = mock.Mock()
         self.mock_test_cls_configs.log_path = '/tmp'
         self.mock_test_cls_configs.user_params = {"some_param": "hahaha"}
         self.mock_test_cls_configs.reporter = mock.MagicMock()
@@ -189,9 +190,11 @@ class BaseTestTest(unittest.TestCase):
         bt_cls = MockBaseTest(self.mock_test_cls_configs)
         bt_cls.run()
         actual_record = bt_cls.results.error[0]
+        skipped_record = bt_cls.results.skipped[0]
+        self.assertIsNone(skipped_record.begin_time)
+        self.assertIsNone(skipped_record.end_time)
         utils.validate_test_result(bt_cls.results)
         self.assertEqual(actual_record.test_name, "setup_class")
-
         self.assertEqual(actual_record.details, MSG_EXPECTED_EXCEPTION)
         self.assertIsNone(actual_record.extras)
         expected_summary = ("Error 1, Executed 0, Failed 0, Passed 0, "
@@ -383,6 +386,7 @@ class BaseTestTest(unittest.TestCase):
 
         class MockBaseTest(base_test.BaseTestClass):
             def on_fail(self, test_name, begin_time):
+                assert self.current_test_name == 'test_something'
                 my_mock("on_fail")
 
             def on_pass(self, test_name, begin_time):
@@ -869,6 +873,8 @@ class BaseTestTest(unittest.TestCase):
         bt_cls = MockBaseTest(self.mock_test_cls_configs)
         bt_cls.run(test_names=["test_func"])
         actual_record = bt_cls.results.skipped[0]
+        self.assertIsNotNone(actual_record.begin_time)
+        self.assertIsNotNone(actual_record.end_time)
         self.assertEqual(actual_record.test_name, "test_func")
         self.assertEqual(actual_record.details, MSG_EXPECTED_EXCEPTION)
         self.assertEqual(actual_record.extras, MOCK_EXTRA)
@@ -884,6 +890,8 @@ class BaseTestTest(unittest.TestCase):
         bt_cls = MockBaseTest(self.mock_test_cls_configs)
         bt_cls.run(test_names=["test_func"])
         actual_record = bt_cls.results.skipped[0]
+        self.assertIsNotNone(actual_record.begin_time)
+        self.assertIsNotNone(actual_record.end_time)
         self.assertEqual(actual_record.test_name, "test_func")
         self.assertEqual(actual_record.details, MSG_EXPECTED_EXCEPTION)
         self.assertEqual(actual_record.extras, MOCK_EXTRA)
diff --git a/tests/mobly/controllers/android_device_lib/callback_handler_test.py b/tests/mobly/controllers/android_device_lib/callback_handler_test.py
index f288ef3..6a3e6d1 100755
--- a/tests/mobly/controllers/android_device_lib/callback_handler_test.py
+++ b/tests/mobly/controllers/android_device_lib/callback_handler_test.py
@@ -39,6 +39,17 @@ class CallbackHandlerTest(unittest.TestCase):
         self.assertGreaterEqual(jsonrpc_client_base._SOCKET_READ_TIMEOUT,
                                 callback_handler.MAX_TIMEOUT)
 
+    def test_callback_id_property(self):
+        mock_event_client = mock.Mock()
+        handler = callback_handler.CallbackHandler(
+            callback_id=MOCK_CALLBACK_ID,
+            event_client=mock_event_client,
+            ret_value=None,
+            method_name=None)
+        self.assertEqual(handler.callback_id, MOCK_CALLBACK_ID)
+        with self.assertRaisesRegex(AttributeError, "can't set attribute"):
+            handler.callback_id = 'ha'
+
     def test_event_dict_to_snippet_event(self):
         mock_event_client = mock.Mock()
         mock_event_client.eventWaitAndGet = mock.Mock(
diff --git a/tests/mobly/controllers/android_device_lib/snippet_client_test.py b/tests/mobly/controllers/android_device_lib/snippet_client_test.py
index beb9262..589bc7f 100755
--- a/tests/mobly/controllers/android_device_lib/snippet_client_test.py
+++ b/tests/mobly/controllers/android_device_lib/snippet_client_test.py
@@ -53,7 +53,7 @@ class MockAdbProxy(object):
                 p=MOCK_PACKAGE_NAME,
                 r=snippet_client._INSTRUMENTATION_RUNNER_PACKAGE), 'utf-8')
         elif 'which' in params:
-            return ''
+            return b''
 
     def __getattr__(self, name):
         """All calls to the none-existent functions in adb proxy would
@@ -70,6 +70,7 @@ class MockAdbProxy(object):
 class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
     """Unit tests for mobly.controllers.android_device_lib.snippet_client.
     """
+
     def test_check_app_installed_normal(self):
         sc = self._make_client()
         sc._check_app_installed()
@@ -78,23 +79,23 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
         sc = self._make_client(MockAdbProxy(apk_not_installed=True))
         expected_msg = '%s is not installed on .*' % MOCK_PACKAGE_NAME
         with self.assertRaisesRegex(jsonrpc_client_base.AppStartError,
-                                     expected_msg):
+                                    expected_msg):
             sc._check_app_installed()
 
     def test_check_app_installed_fail_not_instrumented(self):
         sc = self._make_client(MockAdbProxy(apk_not_instrumented=True))
-        expected_msg = ('%s is installed on .*, but it is not instrumented.'
-                        % MOCK_PACKAGE_NAME)
+        expected_msg = ('%s is installed on .*, but it is not instrumented.' %
+                        MOCK_PACKAGE_NAME)
         with self.assertRaisesRegex(jsonrpc_client_base.AppStartError,
-                                     expected_msg):
+                                    expected_msg):
             sc._check_app_installed()
 
     def test_check_app_installed_fail_target_not_installed(self):
         sc = self._make_client(MockAdbProxy(target_not_installed=True))
-        expected_msg = ('Instrumentation target %s is not installed on .*'
-                        % MOCK_MISSING_PACKAGE_NAME)
+        expected_msg = ('Instrumentation target %s is not installed on .*' %
+                        MOCK_MISSING_PACKAGE_NAME)
         with self.assertRaisesRegex(jsonrpc_client_base.AppStartError,
-                                     expected_msg):
+                                    expected_msg):
             sc._check_app_installed()
 
     @mock.patch('socket.create_connection')
@@ -164,9 +165,9 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
                 'utils.start_standing_subprocess')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.get_available_host_port')
-    def test_snippet_start_app_and_connect_v1(self, mock_get_port,
-                                              mock_start_standing_subprocess,
-                                              mock_create_connection):
+    def test_snippet_start_app_and_connect(self, mock_get_port,
+                                           mock_start_standing_subprocess,
+                                           mock_create_connection):
         self.setup_mock_socket_file(mock_create_connection)
         self._setup_mock_instrumentation_cmd(
             mock_start_standing_subprocess,
@@ -185,18 +186,17 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'SnippetClient._read_protocol_line')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
-                'SnippetClient._connect_to_v1')
+                'SnippetClient.connect')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.get_available_host_port')
-    def test_snippet_start_app_and_connect_v1_persistent_session(
-            self, mock_get_port, mock_connect_to_v1, mock_read_protocol_line,
+    def test_snippet_start_app_and_connect_persistent_session(
+            self, mock_get_port, mock_connect, mock_read_protocol_line,
             mock_check_app_installed, mock_do_start_app):
-
         def _mocked_shell(arg):
             if 'setsid' in arg:
                 raise adb.AdbError('cmd', 'stdout', 'stderr', 'ret_code')
             else:
-                return 'nohup'
+                return b'nohup'
 
         mock_get_port.return_value = 123
         mock_read_protocol_line.side_effect = [
@@ -210,11 +210,10 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
 
         # Test 'setsid' exists
         client = self._make_client()
-        client._adb.shell = mock.Mock(return_value='setsid')
+        client._adb.shell = mock.Mock(return_value=b'setsid')
         client.start_app_and_connect()
         cmd_setsid = '%s am instrument -w -e action start %s/%s' % (
-            snippet_client._SETSID_COMMAND,
-            MOCK_PACKAGE_NAME,
+            snippet_client._SETSID_COMMAND, MOCK_PACKAGE_NAME,
             snippet_client._INSTRUMENTATION_RUNNER_PACKAGE)
         mock_do_start_app.assert_has_calls(mock.call(cmd_setsid))
 
@@ -223,25 +222,20 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
         client._adb.shell = _mocked_shell
         client.start_app_and_connect()
         cmd_nohup = '%s am instrument -w -e action start %s/%s' % (
-            snippet_client._NOHUP_COMMAND,
-            MOCK_PACKAGE_NAME,
+            snippet_client._NOHUP_COMMAND, MOCK_PACKAGE_NAME,
             snippet_client._INSTRUMENTATION_RUNNER_PACKAGE)
-        mock_do_start_app.assert_has_calls([
-            mock.call(cmd_setsid),
-            mock.call(cmd_nohup)
-        ])
+        mock_do_start_app.assert_has_calls(
+            [mock.call(cmd_setsid), mock.call(cmd_nohup)])
 
         # Test both 'setsid' and 'nohup' do not exist
-        client._adb.shell = mock.Mock(
-            side_effect=adb.AdbError('cmd', 'stdout', 'stderr', 'ret_code'))
+        client._adb.shell = mock.Mock(side_effect=adb.AdbError(
+            'cmd', 'stdout', 'stderr', 'ret_code'))
         client = self._make_client()
         client.start_app_and_connect()
         cmd_not_persist = ' am instrument -w -e action start %s/%s' % (
-            MOCK_PACKAGE_NAME,
-            snippet_client._INSTRUMENTATION_RUNNER_PACKAGE)
+            MOCK_PACKAGE_NAME, snippet_client._INSTRUMENTATION_RUNNER_PACKAGE)
         mock_do_start_app.assert_has_calls([
-            mock.call(cmd_setsid),
-            mock.call(cmd_nohup),
+            mock.call(cmd_setsid), mock.call(cmd_nohup),
             mock.call(cmd_not_persist)
         ])
 
@@ -250,9 +244,9 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
                 'utils.start_standing_subprocess')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.get_available_host_port')
-    def test_snippet_start_app_and_connect_v0(self, mock_get_port,
-                                              mock_start_standing_subprocess,
-                                              mock_create_connection):
+    def test_snippet_start_app_crash(self, mock_get_port,
+                                     mock_start_standing_subprocess,
+                                     mock_create_connection):
         mock_get_port.return_value = 456
         self.setup_mock_socket_file(mock_create_connection)
         self._setup_mock_instrumentation_cmd(
@@ -261,8 +255,10 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
                 b'INSTRUMENTATION_RESULT: shortMsg=Process crashed.\n'
             ])
         client = self._make_client()
-        client.start_app_and_connect()
-        self.assertEqual(456, client.device_port)
+        with self.assertRaisesRegex(
+                snippet_client.ProtocolVersionError,
+                'INSTRUMENTATION_RESULT: shortMsg=Process crashed.'):
+            client.start_app_and_connect()
 
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.start_standing_subprocess')
@@ -275,7 +271,8 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
             mock_start_standing_subprocess,
             resp_lines=[b'SNIPPET START, PROTOCOL 99 0\n'])
         client = self._make_client()
-        with self.assertRaises(snippet_client.ProtocolVersionError):
+        with self.assertRaisesRegex(snippet_client.ProtocolVersionError,
+                                    'SNIPPET START, PROTOCOL 99 0'):
             client.start_app_and_connect()
 
     @mock.patch('socket.create_connection')
@@ -283,7 +280,7 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
                 'utils.start_standing_subprocess')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.get_available_host_port')
-    def test_snippet_start_app_and_connect_v1_header_junk(
+    def test_snippet_start_app_and_connect_header_junk(
             self, mock_get_port, mock_start_standing_subprocess,
             mock_create_connection):
         self.setup_mock_socket_file(mock_create_connection)
@@ -300,28 +297,6 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
         client.start_app_and_connect()
         self.assertEqual(123, client.device_port)
 
-    @mock.patch('socket.create_connection')
-    @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
-                'utils.start_standing_subprocess')
-    @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
-                'utils.get_available_host_port')
-    def test_snippet_start_app_and_connect_v0_header_junk(
-            self, mock_get_port, mock_start_standing_subprocess,
-            mock_create_connection):
-        mock_get_port.return_value = 456
-        self.setup_mock_socket_file(mock_create_connection)
-        self._setup_mock_instrumentation_cmd(
-            mock_start_standing_subprocess,
-            resp_lines=[
-                b'This is some header junk\n',
-                b'Some phones print arbitrary output\n',
-                b'\n',
-                b'INSTRUMENTATION_RESULT: shortMsg=Process crashed.\n',
-            ])
-        client = self._make_client()
-        client.start_app_and_connect()
-        self.assertEqual(456, client.device_port)
-
     @mock.patch('socket.create_connection')
     @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
                 'utils.start_standing_subprocess')
@@ -340,12 +315,12 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
                 b'',  # readline uses '' to mark EOF
             ])
         client = self._make_client()
-        with self.assertRaisesRegex(
-                jsonrpc_client_base.AppStartError,
-                'Unexpected EOF waiting for app to start'):
+        with self.assertRaisesRegex(jsonrpc_client_base.AppStartError,
+                                    'Unexpected EOF waiting for app to start'):
             client.start_app_and_connect()
 
-    def _make_client(self, adb_proxy=MockAdbProxy()):
+    def _make_client(self, adb_proxy=None):
+        adb_proxy = adb_proxy or MockAdbProxy()
         return snippet_client.SnippetClient(
             package=MOCK_PACKAGE_NAME, adb_proxy=adb_proxy)
 
diff --git a/tests/mobly/output_test.py b/tests/mobly/output_test.py
new file mode 100755
index 0000000..4bc8e0a
--- /dev/null
+++ b/tests/mobly/output_test.py
@@ -0,0 +1,94 @@
+# Copyright 2017 Google Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import os
+import shutil
+import tempfile
+import unittest
+import yaml
+
+from mobly import config_parser
+from mobly import records
+from mobly import test_runner
+
+from tests.lib import mock_controller
+from tests.lib import integration_test
+
+
+class OutputTest(unittest.TestCase):
+    """This test class has unit tests for the implementation of Mobly's output
+    files.
+    """
+
+    def setUp(self):
+        self.tmp_dir = tempfile.mkdtemp()
+        self.base_mock_test_config = config_parser.TestRunConfig()
+        self.base_mock_test_config.test_bed_name = 'SampleTestBed'
+        self.base_mock_test_config.controller_configs = {}
+        self.base_mock_test_config.user_params = {
+            'icecream': 42,
+            'extra_param': 'haha'
+        }
+        self.base_mock_test_config.log_path = self.tmp_dir
+        self.log_dir = self.base_mock_test_config.log_path
+        self.test_bed_name = self.base_mock_test_config.test_bed_name
+
+    def tearDown(self):
+        shutil.rmtree(self.tmp_dir)
+
+    def test_output(self):
+        """Verifies the expected output files from a test run.
+
+        * Files are correctly created.
+        * Basic sanity checks of each output file.
+        """
+        mock_test_config = self.base_mock_test_config.copy()
+        mock_ctrlr_config_name = mock_controller.MOBLY_CONTROLLER_CONFIG_NAME
+        my_config = [{
+            'serial': 'xxxx',
+            'magic': 'Magic1'
+        }, {
+            'serial': 'xxxx',
+            'magic': 'Magic2'
+        }]
+        mock_test_config.controller_configs[mock_ctrlr_config_name] = my_config
+        tr = test_runner.TestRunner(self.log_dir, self.test_bed_name)
+        tr.add_test_class(mock_test_config, integration_test.IntegrationTest)
+        tr.run()
+        output_dir = os.path.join(self.log_dir, self.test_bed_name, 'latest')
+        summary_file_path = os.path.join(output_dir,
+                                         records.OUTPUT_FILE_SUMMARY)
+        debug_log_path = os.path.join(output_dir,
+                                      records.OUTPUT_FILE_DEBUG_LOG)
+        info_log_path = os.path.join(output_dir, records.OUTPUT_FILE_INFO_LOG)
+        self.assertTrue(os.path.isfile(summary_file_path))
+        self.assertTrue(os.path.isfile(debug_log_path))
+        self.assertTrue(os.path.isfile(info_log_path))
+        summary_entries = []
+        with open(summary_file_path) as f:
+            for entry in yaml.load_all(f):
+                self.assertTrue(entry['Type'])
+                summary_entries.append(entry)
+        with open(debug_log_path, 'r') as f:
+            content = f.read()
+            self.assertIn('DEBUG', content)
+            self.assertIn('INFO', content)
+        with open(info_log_path, 'r') as f:
+            content = f.read()
+            self.assertIn('INFO', content)
+            self.assertNotIn('DEBUG', content)
+
+
+if __name__ == "__main__":
+    unittest.main()
diff --git a/tests/mobly/records_test.py b/tests/mobly/records_test.py
index 51b9e28..a5f68db 100755
--- a/tests/mobly/records_test.py
+++ b/tests/mobly/records_test.py
@@ -12,6 +12,11 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import os
+import shutil
+import tempfile
+import yaml
+
 from future.tests.base import unittest
 
 from mobly import records
@@ -28,6 +33,10 @@ class RecordsTest(unittest.TestCase):
         self.details = "Some details about the test execution."
         self.float_extra = 12345.56789
         self.json_extra = {"ha": "whatever"}
+        self.tmp_path = tempfile.mkdtemp()
+
+    def tearDown(self):
+        shutil.rmtree(self.tmp_path)
 
     def verify_record(self, record, result, details, extras):
         # Verify each field.
@@ -295,6 +304,19 @@ class RecordsTest(unittest.TestCase):
         self.assertTrue(tr.is_test_executed(record1.test_name))
         self.assertFalse(tr.is_test_executed(self.tn + 'ha'))
 
+    def test_summary_write_dump(self):
+        s = signals.TestFailure(self.details, self.float_extra)
+        record1 = records.TestResultRecord(self.tn)
+        record1.test_begin()
+        record1.test_fail(s)
+        dump_path = os.path.join(self.tmp_path, 'ha.yaml')
+        writer = records.TestSummaryWriter(dump_path)
+        writer.dump(record1.to_dict(), records.TestSummaryEntryType.RECORD)
+        with open(dump_path, 'r') as f:
+            content = yaml.load(f)
+            self.assertEqual(content['Type'],
+                             records.TestSummaryEntryType.RECORD.value)
+
 
 if __name__ == "__main__":
     unittest.main()
diff --git a/tests/mobly/test_runner_test.py b/tests/mobly/test_runner_test.py
index e57a91f..17d54c3 100755
--- a/tests/mobly/test_runner_test.py
+++ b/tests/mobly/test_runner_test.py
@@ -13,11 +13,14 @@
 # limitations under the License.
 
 import mock
+import os
 import shutil
 import tempfile
+import yaml
 from future.tests.base import unittest
 
 from mobly import config_parser
+from mobly import records
 from mobly import signals
 from mobly import test_runner
 
@@ -31,6 +34,7 @@ class TestRunnerTest(unittest.TestCase):
     """This test class has unit tests for the implementation of everything
     under mobly.test_runner.
     """
+
     def setUp(self):
         self.tmp_dir = tempfile.mkdtemp()
         self.base_mock_test_config = config_parser.TestRunConfig()
@@ -50,7 +54,7 @@ class TestRunnerTest(unittest.TestCase):
     def test_register_controller_no_config(self):
         tr = test_runner.TestRunner(self.log_dir, self.test_bed_name)
         with self.assertRaisesRegex(signals.ControllerError,
-                                     'No corresponding config found for'):
+                                    'No corresponding config found for'):
             tr._register_controller(self.base_mock_test_config,
                                     mock_controller)
 
@@ -177,6 +181,37 @@ class TestRunnerTest(unittest.TestCase):
         }
         self.assertEqual(tr.results.controller_info, expected_info)
 
+    def test_summary_file_entries(self):
+        """Verifies the output summary's file format.
+
+        This focuses on the format of the file instead of the content of
+        entries, which is covered in base_test_test.
+        """
+        mock_test_config = self.base_mock_test_config.copy()
+        mock_ctrlr_config_name = mock_controller.MOBLY_CONTROLLER_CONFIG_NAME
+        my_config = [{
+            'serial': 'xxxx',
+            'magic': 'Magic1'
+        }, {
+            'serial': 'xxxx',
+            'magic': 'Magic2'
+        }]
+        mock_test_config.controller_configs[mock_ctrlr_config_name] = my_config
+        tr = test_runner.TestRunner(self.log_dir, self.test_bed_name)
+        tr.add_test_class(mock_test_config, integration_test.IntegrationTest)
+        tr.run()
+        summary_path = os.path.join(mock_test_config.log_path,
+                                    mock_test_config.test_bed_name, 'latest',
+                                    records.OUTPUT_FILE_SUMMARY)
+        with open(summary_path, 'r') as f:
+            summary_entries = list(yaml.load_all(f))
+        self.assertEqual(len(summary_entries), 4)
+        # Verify the first entry is the list of test names.
+        self.assertEqual(summary_entries[0]['Type'],
+                         records.TestSummaryEntryType.TEST_NAME_LIST.value)
+        self.assertEqual(summary_entries[1]['Type'],
+                         records.TestSummaryEntryType.RECORD.value)
+
     @mock.patch(
         'mobly.controllers.android_device_lib.adb.AdbProxy',
         return_value=mock_android_device.MockAdbProxy(1))
@@ -265,8 +300,7 @@ class TestRunnerTest(unittest.TestCase):
 
     def test_run_no_tests(self):
         tr = test_runner.TestRunner(self.log_dir, self.test_bed_name)
-        with self.assertRaisesRegex(test_runner.Error,
-                                     'No tests to execute.'):
+        with self.assertRaisesRegex(test_runner.Error, 'No tests to execute.'):
             tr.run()
 
     def test_verify_controller_module(self):
@@ -292,6 +326,18 @@ class TestRunnerTest(unittest.TestCase):
         finally:
             setattr(mock_controller, 'MOBLY_CONTROLLER_CONFIG_NAME', tmp)
 
+    @mock.patch(
+        'mobly.test_runner._find_test_class',
+        return_value=type('SampleTest', (), {}))
+    @mock.patch(
+        'mobly.test_runner.config_parser.load_test_config_file',
+        return_value=[config_parser.TestRunConfig()])
+    @mock.patch('mobly.test_runner.TestRunner', return_value=mock.MagicMock())
+    def test_main_parse_args(self, mock_test_runner, mock_config,
+                             mock_find_test):
+        test_runner.main(['-c', 'some/path/foo.yaml', '-b', 'hello'])
+        mock_config.assert_called_with('some/path/foo.yaml', None)
+
 
 if __name__ == "__main__":
     unittest.main()
diff --git a/tests/mobly/utils_test.py b/tests/mobly/utils_test.py
index 1e2cdc1..cc24cbf 100755
--- a/tests/mobly/utils_test.py
+++ b/tests/mobly/utils_test.py
@@ -18,6 +18,7 @@ import time
 from future.tests.base import unittest
 
 import portpicker
+import psutil
 from mobly import utils
 
 MOCK_AVAILABLE_PORT = 5
@@ -27,21 +28,17 @@ class UtilsTest(unittest.TestCase):
     """This test class has unit tests for the implementation of everything
     under mobly.utils.
     """
+
     def test_start_standing_subproc(self):
-        with self.assertRaisesRegex(utils.Error, 'Process .* has terminated'):
-            utils.start_standing_subprocess(
-                ['sleep', '0'], check_health_delay=0.5)
+        p = utils.start_standing_subprocess(['sleep', '1'])
+        p1 = psutil.Process(p.pid)
+        self.assertTrue(p1.is_running())
 
     def test_stop_standing_subproc(self):
-        p = utils.start_standing_subprocess(['sleep', '5'])
+        p = utils.start_standing_subprocess(['sleep', '4'])
+        p1 = psutil.Process(p.pid)
         utils.stop_standing_subprocess(p)
-        self.assertIsNotNone(p.poll())
-
-    def test_stop_standing_subproc_already_dead(self):
-        p = utils.start_standing_subprocess(['sleep', '0'])
-        time.sleep(0.5)
-        with self.assertRaisesRegex(utils.Error, 'Process .* has terminated'):
-            utils.stop_standing_subprocess(p)
+        self.assertFalse(p1.is_running())
 
     @mock.patch(
         'mobly.controllers.android_device_lib.adb.list_occupied_adb_ports')