Sets default not to do verbose logging (#683)
Add support to not log full RPC responses.
Some RPC responses can be large, logging every single one of them can make the log file too big to be useful for debugging.
diff --git a/mobly/controllers/android_device_lib/jsonrpc_client_base.py b/mobly/controllers/android_device_lib/jsonrpc_client_base.py
index 160ee83..0e8608b 100644
--- a/mobly/controllers/android_device_lib/jsonrpc_client_base.py
+++ b/mobly/controllers/android_device_lib/jsonrpc_client_base.py
@@ -70,6 +70,10 @@
# Maximum time to wait for a response message on the socket.
_SOCKET_READ_TIMEOUT = callback_handler.MAX_TIMEOUT
+# Maximum logging length of Rpc response in DEBUG level when verbose logging is
+# off.
+_MAX_RPC_RESP_LOGGING_LENGTH = 1024
+
class Error(errors.DeviceError):
pass
@@ -138,6 +142,7 @@
self._counter = None
self._lock = threading.Lock()
self._event_client = None
+ self.verbose_logging = True
def __del__(self):
self.disconnect()
@@ -292,7 +297,17 @@
"""
try:
response = self._client.readline()
- self.log.debug('Snippet received: %s', response)
+ response_log = str(response)
+ if self.verbose_logging:
+ self.log.debug('Snippet received: %s', response)
+ else:
+ if _MAX_RPC_RESP_LOGGING_LENGTH >= len(response):
+ self.log.debug('Snippet received: %s', response)
+ else:
+ self.log.debug(
+ 'Snippet received: %s... %d chars are truncated',
+ response_log[:_MAX_RPC_RESP_LOGGING_LENGTH],
+ len(response) - _MAX_RPC_RESP_LOGGING_LENGTH)
return response
except socket.error as e:
raise Error(
@@ -377,3 +392,19 @@
while True:
yield i
i += 1
+
+ def set_snippet_client_verbose_logging(self, verbose):
+ """Switches verbose logging. True for logging full RPC response.
+
+ By default it will only write max_rpc_return_value_length for Rpc return
+ strings. If you need to see full message returned from Rpc, please turn
+ on verbose logging.
+
+ max_rpc_return_value_length will set to 1024 by default, the length
+ contains full Rpc response in Json format, included 1st element "id".
+
+ Args:
+ verbose: bool. If True, turns on verbose logging, if False turns off
+ """
+ self._ad.log.info('Set verbose logging to %s.', verbose)
+ self.verbose_logging = verbose
diff --git a/tests/lib/jsonrpc_client_test_base.py b/tests/lib/jsonrpc_client_test_base.py
index c4ca7a8..b033771 100755
--- a/tests/lib/jsonrpc_client_test_base.py
+++ b/tests/lib/jsonrpc_client_test_base.py
@@ -11,7 +11,8 @@
# 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 random
+import string
from builtins import str
import mock
@@ -39,6 +40,9 @@
b'{"id": 0, "result": 123, "error": null, "status": 1, "uid": 1, '
b'"callback": "1-0"}')
MOCK_RESP_WITH_ERROR = b'{"id": 0, "error": 1, "status": 1, "uid": 1}'
+ MOCK_RESP_FLEXIABLE_RESULT_LENGTH = (
+ '{"id": 0, "result": "%s", "error": null, "status": 0, "callback": null}'
+ )
class MockSocketFile(object):
def __init__(self, resp):
@@ -69,3 +73,13 @@
fake_conn.makefile.return_value = fake_file
mock_create_connection.return_value = fake_conn
return fake_file
+
+ def generate_rpc_response(self, response_length=1024):
+ # TODO: Py2 deprecation
+ # .encode('utf-8') is for py2 compatibility, after py2 deprecation, it
+ # could be modified to byte('xxxxx', 'utf-8')
+ return bytes((self.MOCK_RESP_FLEXIABLE_RESULT_LENGTH % ''.join(
+ random.choice(string.ascii_lowercase)
+ for i in range(response_length -
+ len(self.MOCK_RESP_FLEXIABLE_RESULT_LENGTH) + 2))
+ ).encode('utf-8'))
diff --git a/tests/mobly/controllers/android_device_lib/jsonrpc_client_base_test.py b/tests/mobly/controllers/android_device_lib/jsonrpc_client_base_test.py
index 7be4190..063ab4e 100755
--- a/tests/mobly/controllers/android_device_lib/jsonrpc_client_base_test.py
+++ b/tests/mobly/controllers/android_device_lib/jsonrpc_client_base_test.py
@@ -228,6 +228,84 @@
self.assertEqual(next(client._counter), 10)
+ @mock.patch('socket.create_connection')
+ def test_rpc_verbose_logging_with_long_string(self,
+ mock_create_connection):
+ """Test rpc response fully write into DEBUG level log."""
+ fake_file = self.setup_mock_socket_file(mock_create_connection)
+ testing_rpc_response = self.generate_rpc_response(4000)
+ fake_file.resp = testing_rpc_response
+
+ client = FakeRpcClient()
+ client.connect()
+
+ response = client._client_receive()
+ self.assertEqual(response, testing_rpc_response)
+
+ client.log.debug.assert_called_with('Snippet received: %s',
+ testing_rpc_response)
+
+ @mock.patch('socket.create_connection')
+ def test_rpc_truncated_logging_short_response(self,
+ mock_create_connection):
+ """Test rpc response will full logged when length is short."""
+ fake_file = self.setup_mock_socket_file(mock_create_connection)
+ testing_rpc_response = self.generate_rpc_response(
+ int(jsonrpc_client_base._MAX_RPC_RESP_LOGGING_LENGTH / 2))
+ fake_file.resp = testing_rpc_response
+
+ client = FakeRpcClient()
+ client.connect()
+
+ client.set_snippet_client_verbose_logging(False)
+ response = client._client_receive()
+
+ self.assertEqual(response, testing_rpc_response)
+ client.log.debug.assert_called_with('Snippet received: %s',
+ testing_rpc_response)
+
+ @mock.patch('socket.create_connection')
+ def test_rpc_truncated_logging_fit_size_response(self,
+ mock_create_connection):
+ """Test rpc response will full logged when length is equal to threshold.
+ """
+ fake_file = self.setup_mock_socket_file(mock_create_connection)
+ testing_rpc_response = self.generate_rpc_response(
+ jsonrpc_client_base._MAX_RPC_RESP_LOGGING_LENGTH)
+ fake_file.resp = testing_rpc_response
+
+ client = FakeRpcClient()
+ client.connect()
+
+ client.set_snippet_client_verbose_logging(False)
+ response = client._client_receive()
+
+ self.assertEqual(response, testing_rpc_response)
+ client.log.debug.assert_called_with('Snippet received: %s',
+ testing_rpc_response)
+
+ @mock.patch('socket.create_connection')
+ def test_rpc_truncated_logging_long_response(self, mock_create_connection):
+ """Test rpc response truncated with given length in DEBUG level log."""
+ fake_file = self.setup_mock_socket_file(mock_create_connection)
+ resp_len = jsonrpc_client_base._MAX_RPC_RESP_LOGGING_LENGTH * 40
+ testing_rpc_response = self.generate_rpc_response(resp_len)
+ fake_file.resp = testing_rpc_response
+
+ client = FakeRpcClient()
+ client.connect()
+
+ client.set_snippet_client_verbose_logging(False)
+ response = client._client_receive()
+
+ self.assertEqual(response, testing_rpc_response)
+ # DEBUG level log should truncated by given length.
+ client.log.debug.assert_called_with(
+ 'Snippet received: %s... %d chars are truncated',
+ str(testing_rpc_response)
+ [:jsonrpc_client_base._MAX_RPC_RESP_LOGGING_LENGTH],
+ resp_len - jsonrpc_client_base._MAX_RPC_RESP_LOGGING_LENGTH)
+
if __name__ == '__main__':
unittest.main()
