Repository: google/mobly

Issue:
Snippet crashes on phones that print extra instrumentation output.
Some phones print extra information prior to instrumentation output. On such phones, the snippet crashes.

Discussion:
dthkao: 



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

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 189 at r1](https://reviewable.io:443/reviews/google/mobly/227#-KlblfMBHGUVsYsb35BX:-KlblfMC2k4pyw9i44TT:b879d2f) ([raw file](https://github.com/google/mobly/blob/3606e54d198968fa807da58991817244a73b1fb5/mobly/controllers/android_device_lib/snippet_client.py#L189)):*
> ```Python
>         self._adb.forward(
>             ['tcp:%d' % self.host_port,
>              'tcp:%d' % self.device_port])
> ```

this was the autoformatter?

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 221 at r1](https://reviewable.io:443/reviews/google/mobly/227#-KlblqEfvw26Ok0DC1qe:-KlblqEfvw26Ok0DC1qf:botn7lo) ([raw file](https://github.com/google/mobly/blob/3606e54d198968fa807da58991817244a73b1fb5/mobly/controllers/android_device_lib/snippet_client.py#L221)):*
> ```Python
> 
>     def _read_line(self):
>         while True:
> ```

what if we never get an acceptable line?

---


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

adorokhine: 



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

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 189 at r1](https://reviewable.io:443/reviews/google/mobly/227#-KlblfMBHGUVsYsb35BX:-Klbm9igg1oyi650B6wP:b2nhtan) ([raw file](https://github.com/google/mobly/blob/3606e54d198968fa807da58991817244a73b1fb5/mobly/controllers/android_device_lib/snippet_client.py#L189)):*
<details><summary><i>Previously, dthkao (David T.H. Kao) wrote…</i></summary><blockquote>

this was the autoformatter?
</blockquote></details>

Yup

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 221 at r1](https://reviewable.io:443/reviews/google/mobly/227#-KlblqEfvw26Ok0DC1qe:-KlboFdOyj5NPihjPUAj:b-896fix) ([raw file](https://github.com/google/mobly/blob/3606e54d198968fa807da58991817244a73b1fb5/mobly/controllers/android_device_lib/snippet_client.py#L221)):*
<details><summary><i>Previously, dthkao (David T.H. Kao) wrote…</i></summary><blockquote>

what if we never get an acceptable line?
</blockquote></details>

Done.

---


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

dthkao: <img class="emoji" title=":lgtm:" alt=":lgtm:" align="absmiddle" src="https://reviewable.io/lgtm.png" height="20" width="61"/>

---

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

---



*Comments from [Reviewable](https://reviewable.io:443/reviews/google/mobly/227#-:-Klbp4-Zgil5GlAXMhnK:bnfp4nl)*
<!-- Sent from Reviewable.io -->

xpconanfan: 



Review status: 0 of 2 files reviewed at latest revision, 3 unresolved discussions.

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 227 at r2](https://reviewable.io:443/reviews/google/mobly/227#-KldwJjmq90v1vEAzqiZ:-KldwJjnZt2xIGaxbdo0:bn32ide) ([raw file](https://github.com/google/mobly/blob/f618e1ff6ce4ee08d35e28c5b5dfb9192d347e5c/mobly/controllers/android_device_lib/snippet_client.py#L227)):*
> ```Python
>                     'Unexpected EOF waiting for app to start')
>             line = line.strip()
>             if (line.startswith('INSTRUMENTATION_RESULT:') or
> ```

So this readline function is really only looking for a couple of particular lines?
Could we rename the function to reflect this and add docstring?
`_read_line` sounds like a generic function that reads any line.

---


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

xpconanfan: 



Review status: 0 of 2 files reviewed at latest revision, 4 unresolved discussions.

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 226 at r2](https://reviewable.io:443/reviews/google/mobly/227#-KldxLWGMgBkeXLklRXg:-KldxLWGMgBkeXLklRXh:b-3b3kof) ([raw file](https://github.com/google/mobly/blob/f618e1ff6ce4ee08d35e28c5b5dfb9192d347e5c/mobly/controllers/android_device_lib/snippet_client.py#L226)):*
> ```Python
>                 raise jsonrpc_client_base.AppStartError(
>                     'Unexpected EOF waiting for app to start')
>             line = line.strip()
> ```

Shouldn't we strip before we do `not line` check?

---


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

adorokhine: 



Review status: 0 of 2 files reviewed at latest revision, 4 unresolved discussions.

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 226 at r2](https://reviewable.io:443/reviews/google/mobly/227#-KldxLWGMgBkeXLklRXg:-Kle85GDasmQERQlc-4K:bwju1v5) ([raw file](https://github.com/google/mobly/blob/f618e1ff6ce4ee08d35e28c5b5dfb9192d347e5c/mobly/controllers/android_device_lib/snippet_client.py#L226)):*
<details><summary><i>Previously, xpconanfan (Ang Li) wrote…</i></summary><blockquote>

Shouldn't we strip before we do `not line` check?
</blockquote></details>

Actually we can't, because readline() returns '' for EOF and '\n' for regular empty lines. So if we strip before the 'not line' check, we would consider any empty line in the output to be the same as EOF. Added a comment to this effect.

---

*[mobly/controllers/android_device_lib/snippet_client.py, line 227 at r2](https://reviewable.io:443/reviews/google/mobly/227#-KldwJjmq90v1vEAzqiZ:-Kle84qz-_723Td_9_EB:b-896fix) ([raw file](https://github.com/google/mobly/blob/f618e1ff6ce4ee08d35e28c5b5dfb9192d347e5c/mobly/controllers/android_device_lib/snippet_client.py#L227)):*
<details><summary><i>Previously, xpconanfan (Ang Li) wrote…</i></summary><blockquote>

So this readline function is really only looking for a couple of particular lines?
Could we rename the function to reflect this and add docstring?
`_read_line` sounds like a generic function that reads any line.
</blockquote></details>

Done.

---


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

xpconanfan: <img class="emoji" title=":lgtm:" alt=":lgtm:" align="absmiddle" src="https://reviewable.io/lgtm.png" height="20" width="61"/>

---

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

---



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


Patch:
diff --git a/mobly/controllers/android_device_lib/snippet_client.py b/mobly/controllers/android_device_lib/snippet_client.py
index 4eb15e8..769140f 100644
--- a/mobly/controllers/android_device_lib/snippet_client.py
+++ b/mobly/controllers/android_device_lib/snippet_client.py
@@ -1,11 +1,11 @@
 # Copyright 2016 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.
@@ -42,7 +42,7 @@ class Error(Exception):
     pass
 
 
-class ProtocolVersionError(Error):
+class ProtocolVersionError(jsonrpc_client_base.AppStartError):
     """Raised when the protocol reported by the snippet is unknown."""
 
 
@@ -92,7 +92,7 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
         # just warn and retry as v0.
         # TODO(adorokhine): delete this in Mobly 1.6 when snippet v0 support is
         # removed.
-        line = self._read_line()
+        line = self._read_protocol_line()
         if line in ('INSTRUMENTATION_RESULT: shortMsg=Process crashed.',
                     'INSTRUMENTATION_RESULT: shortMsg='
                     'java.lang.IllegalArgumentException'):
@@ -185,7 +185,8 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
     def _connect_to_v0(self):
         self.device_port = self.host_port
         self._adb.forward(
-            ['tcp:%d' % self.host_port, 'tcp:%d' % self.device_port])
+            ['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:
@@ -203,19 +204,46 @@ class SnippetClient(jsonrpc_client_base.JsonRpcClientBase):
             '%s failed to start on %s.' % (self.package, self._adb.serial))
 
     def _connect_to_v1(self):
-        line = self._read_line()
+        line = self._read_protocol_line()
         match = re.match('^SNIPPET SERVING, PORT ([0-9]+)$', line)
         if not match:
-            raise ProtocolVersionError(line)
+            raise jsonrpc_client_base.AppStartError(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()
         self._adb.forward(
-            ['tcp:%d' % self.host_port, 'tcp:%d' % self.device_port])
+            ['tcp:%d' % self.host_port,
+             'tcp:%d' % self.device_port])
         self.connect()
 
-    def _read_line(self):
-        line = self._proc.stdout.readline().rstrip()
-        self.log.debug('Read line from instrumentation output: "%s"', line)
-        return line
+    def _read_protocol_line(self):
+        """Reads the next line of instrumentation output relevant to snippets.
+
+        This method will skip over lines that don't start with 'SNIPPET' or
+        'INSTRUMENTATION_RESULT'.
+
+        Returns:
+            (str) Next line of snippet-related instrumentation output, stripped.
+
+        Raises:
+            jsonrpc_client_base.AppStartError: If EOF is reached without any
+                                               protocol lines being read.
+        """
+        while True:
+            line = self._proc.stdout.readline().decode('utf-8')
+            if not line:
+                raise jsonrpc_client_base.AppStartError(
+                    'Unexpected EOF waiting for app to start')
+            # readline() uses an empty string to mark EOF, and a single newline
+            # to mark regular empty lines in the output. Don't move the strip()
+            # call above the truthiness check, or this method will start
+            # considering any blank output line to be EOF.
+            line = line.strip()
+            if (line.startswith('INSTRUMENTATION_RESULT:') or
+                    line.startswith('SNIPPET ')):
+                self.log.debug(
+                    'Accepted line from instrumentation output: "%s"', line)
+                return line
+            self.log.debug('Discarded line from instrumentation output: "%s"',
+                           line)


Test patch:
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 911f53e..244be5f 100755
--- a/tests/mobly/controllers/android_device_lib/snippet_client_test.py
+++ b/tests/mobly/controllers/android_device_lib/snippet_client_test.py
@@ -1,11 +1,11 @@
 # 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.
@@ -120,10 +120,129 @@ class SnippetClientTest(jsonrpc_client_test_base.JsonRpcClientTestBase):
         with self.assertRaisesRegexp(jsonrpc_client_base.ApiError, '1'):
             callback.getAll('eventName')
 
+    @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_v1(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,
+            resp_lines=[
+                b'SNIPPET START, PROTOCOL 1 0\n',
+                b'SNIPPET SERVING, PORT 123\n',
+            ])
+        client = self._make_client()
+        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(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'INSTRUMENTATION_RESULT: shortMsg=Process crashed.\n'])
+        client = self._make_client()
+        client.start_app_and_connect()
+        self.assertEqual(456, client.device_port)
+
+    @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
+                'utils.start_standing_subprocess')
+    def test_snippet_start_app_and_connect_unknown_protocol(
+            self, mock_start_standing_subprocess):
+        self._setup_mock_instrumentation_cmd(
+            mock_start_standing_subprocess,
+            resp_lines=[b'SNIPPET START, PROTOCOL 99 0\n'])
+        client = self._make_client()
+        with self.assertRaises(snippet_client.ProtocolVersionError):
+            client.start_app_and_connect()
+
+    @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_v1_header_junk(
+            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,
+            resp_lines=[
+                b'This is some header junk\n',
+                b'Some phones print arbitrary output\n',
+                b'SNIPPET START, PROTOCOL 1 0\n',
+                b'Maybe in the middle too\n',
+                b'SNIPPET SERVING, PORT 123\n',
+            ])
+        client = self._make_client()
+        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')
+    @mock.patch('mobly.controllers.android_device_lib.snippet_client.'
+                'utils.get_available_host_port')
+    def test_snippet_start_app_and_connect_no_valid_line(
+            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'',  # readline uses '' to mark EOF
+            ])
+        client = self._make_client()
+        with self.assertRaisesRegexp(
+                jsonrpc_client_base.AppStartError,
+                'Unexpected EOF waiting for app to start'):
+            client.start_app_and_connect()
+
     def _make_client(self, adb_proxy=MockAdbProxy()):
         return snippet_client.SnippetClient(
             package=MOCK_PACKAGE_NAME, adb_proxy=adb_proxy)
 
+    def _setup_mock_instrumentation_cmd(self, mock_start_standing_subprocess,
+                                        resp_lines):
+        mock_proc = mock_start_standing_subprocess()
+        mock_proc.stdout.readline.side_effect = resp_lines
+
 
 if __name__ == "__main__":
     unittest.main()