Cert: Add --verbose mode to dumps logs from subprocesses to STDOUT (e48841ff) · Commits · e / os / android_packages_modules_Bluetooth

system/gd/cert/gd_base_test.py

+33 −5

Original line number	Diff line number	Diff line
		@@ -14,6 +14,7 @@
		# See the License for the specific language governing permissions and
		# limitations under the License.

		import concurrent.futures
		import importlib
		import logging
		import os
		@@ -32,6 +33,8 @@ from cert.os_utils import get_gd_root
		from cert.os_utils import read_crash_snippet_and_log_tail
		from cert.os_utils import is_subprocess_alive
		from cert.os_utils import make_ports_available
		from cert.os_utils import TerminalColor
		from cert.gd_device import ACTS_CONTROLLER_CONFIG_NAME as CONTROLLER_CONFIG_NAME
		from facade import rootservice_pb2 as facade_rootservice


		@@ -43,6 +46,9 @@ class GdBaseTestClass(BaseTestClass):
		self.dut_module = dut_module
		self.cert_module = cert_module
		self.log_path_base = get_current_context().get_full_output_path()
		self.verbose_mode = bool(self.user_params.get('verbose_mode', False))
		for config in self.controller_configs[CONTROLLER_CONFIG_NAME]:
		config['verbose_mode'] = self.verbose_mode

		# Start root-canal if needed
		self.rootcanal_running = False
		@@ -57,8 +63,6 @@ class GdBaseTestClass(BaseTestClass):
		# Get root canal log
		self.rootcanal_logpath = os.path.join(self.log_path_base,
		'rootcanal_logs.txt')
		self.rootcanal_logs = open(self.rootcanal_logpath, 'w')

		# Make sure ports are available
		rootcanal_config = self.controller_configs['rootcanal']
		rootcanal_test_port = int(rootcanal_config.get("test_port", "6401"))
		@@ -80,8 +84,9 @@ class GdBaseTestClass(BaseTestClass):
		],
		cwd=get_gd_root(),
		env=os.environ.copy(),
		stdout=self.rootcanal_logs,
		stderr=self.rootcanal_logs)
		stdout=subprocess.PIPE,
		stderr=subprocess.STDOUT,
		universal_newlines=True)
		asserts.assert_true(
		self.rootcanal_process,
		msg="Cannot start root-canal at " + str(rootcanal))
		@@ -89,6 +94,11 @@ class GdBaseTestClass(BaseTestClass):
		is_subprocess_alive(self.rootcanal_process),
		msg="root-canal stopped immediately after running")

		self.rootcanal_logging_executor = concurrent.futures.ThreadPoolExecutor(
		max_workers=1)
		self.rootcanal_logging_future = self.rootcanal_logging_executor.submit(
		self.__rootcanal_logging_loop)

		# Modify the device config to include the correct root-canal port
		for gd_device_config in self.controller_configs.get("GdDevice"):
		gd_device_config["rootcanal_port"] = str(rootcanal_hci_port)
		@@ -99,6 +109,14 @@ class GdBaseTestClass(BaseTestClass):
		self.dut = self.gd_devices[1]
		self.cert = self.gd_devices[0]

		def __rootcanal_logging_loop(self):
		with open(self.rootcanal_logpath, 'w') as rootcanal_log:
		for line in self.rootcanal_process.stdout:
		rootcanal_log.write(line)
		if self.verbose_mode:
		print("[%s%s%s] %s" % (TerminalColor.MAGENTA, "root_canal",
		TerminalColor.END, line.strip()))

		def teardown_class(self):
		if self.rootcanal_running:
		stop_signal = signal.SIGINT
		@@ -120,7 +138,17 @@ class GdBaseTestClass(BaseTestClass):
		return_code = -65536
		if return_code != 0 and return_code != -stop_signal:
		logging.error("rootcanal stopped with code: %d" % return_code)
		self.rootcanal_logs.close()
		try:
		result = self.rootcanal_logging_future.result(
		timeout=self.SUBPROCESS_WAIT_TIMEOUT_SECONDS)
		if result:
		logging.error(
		"rootcanal process logging thread produced an error when executing: %s"
		% str(result))
		except concurrent.futures.TimeoutError:
		logging.error(
		"rootcanal process logging thread failed to finish on time")
		self.rootcanal_logging_executor.shutdown(wait=False)

		def setup_test(self):
		self.dut.rootservice.StartStack(

system/gd/cert/gd_device.py

+44 −12

Original line number	Diff line number	Diff line
		@@ -15,6 +15,7 @@
		# limitations under the License.

		from abc import ABC
		import concurrent.futures
		import inspect
		import logging
		import os
		@@ -24,7 +25,6 @@ import signal
		import socket
		import subprocess
		import time
		import re
		from typing import List

		import grpc
		@@ -40,6 +40,7 @@ from cert.os_utils import get_gd_root
		from cert.os_utils import read_crash_snippet_and_log_tail
		from cert.os_utils import is_subprocess_alive
		from cert.os_utils import make_ports_available
		from cert.os_utils import TerminalColor
		from facade import rootservice_pb2_grpc as facade_rootservice_pb2_grpc
		from hal import facade_pb2_grpc as hal_facade_pb2_grpc
		from hci.facade import facade_pb2_grpc as hci_facade_pb2_grpc
		@@ -86,17 +87,18 @@ def get_instances_with_configs(configs):
		for arg in config["cmd"]:
		logging.debug(arg)
		resolved_cmd.append(replace_vars(arg, config))
		verbose_mode = bool(config.get('verbose_mode', False))
		if config.get("serial_number"):
		device = GdAndroidDevice(
		config["grpc_port"], config["grpc_root_server_port"],
		config["signal_port"], resolved_cmd, config["label"],
		ACTS_CONTROLLER_CONFIG_NAME, config["name"],
		config["serial_number"])
		config["serial_number"], verbose_mode)
		else:
		device = GdHostOnlyDevice(
		config["grpc_port"], config["grpc_root_server_port"],
		config["signal_port"], resolved_cmd, config["label"],
		ACTS_CONTROLLER_CONFIG_NAME, config["name"])
		ACTS_CONTROLLER_CONFIG_NAME, config["name"], verbose_mode)
		device.setup()
		devices.append(device)
		return devices
		@@ -135,7 +137,7 @@ class GdDeviceBase(ABC):

		def __init__(self, grpc_port: str, grpc_root_server_port: str,
		signal_port: str, cmd: List[str], label: str,
		type_identifier: str, name: str):
		type_identifier: str, name: str, verbose_mode: bool):
		"""Base GD device, common traits for both device based and host only GD
		cert tests
		:param grpc_port: main gRPC service port
		@@ -151,12 +153,14 @@ class GdDeviceBase(ABC):
		arguments = [
		values[arg]
		for arg in inspect.getfullargspec(GdDeviceBase.__init__).args
		if arg != "verbose_mode"
		]
		asserts.assert_true(
		all(arguments),
		"All arguments to GdDeviceBase must not be None nor empty")
		asserts.assert_true(
		all(cmd), "cmd list should not have None nor empty component")
		self.verbose_mode = verbose_mode
		self.grpc_root_server_port = int(grpc_root_server_port)
		self.grpc_port = int(grpc_port)
		self.signal_port = int(signal_port)
		@@ -175,6 +179,18 @@ class GdDeviceBase(ABC):
		self.log_path_base, '%s_btsnoop_hci.log' % self.label))
		self.cmd = cmd
		self.environment = os.environ.copy()
		if "cert" in self.label:
		self.terminal_color = TerminalColor.BLUE
		else:
		self.terminal_color = TerminalColor.YELLOW

		def __backing_process_logging_loop(self):
		with open(self.backing_process_log_path, 'w') as backing_process_log:
		for line in self.backing_process.stdout:
		backing_process_log.write(line)
		if self.verbose_mode:
		print("[%s%s%s] %s" % (self.terminal_color, self.label,
		TerminalColor.END, line.strip()))

		def setup(self):
		"""Set up this device for test, must run before using this device
		@@ -195,13 +211,13 @@ class GdDeviceBase(ABC):
		signal_socket.listen(1)

		# Start backing process
		self.backing_process_logs = open(self.backing_process_log_path, 'w')
		self.backing_process = subprocess.Popen(
		self.cmd,
		cwd=get_gd_root(),
		env=self.environment,
		stdout=self.backing_process_logs,
		stderr=self.backing_process_logs)
		stdout=subprocess.PIPE,
		stderr=subprocess.STDOUT,
		universal_newlines=True)
		asserts.assert_true(
		self.backing_process,
		msg="Cannot start backing_process at " + " ".join(self.cmd))
		@@ -213,6 +229,11 @@ class GdDeviceBase(ABC):
		# Wait for process to be ready
		signal_socket.accept()

		self.backing_process_logging_executor = concurrent.futures.ThreadPoolExecutor(
		max_workers=1)
		self.backing_process_logging_future = self.backing_process_logging_executor.submit(
		self.__backing_process_logging_loop)

		# Setup gRPC management channels
		self.grpc_root_server_channel = grpc.insecure_channel(
		"localhost:%d" % self.grpc_root_server_port)
		@@ -283,7 +304,17 @@ class GdDeviceBase(ABC):
		if return_code not in [-stop_signal, 0]:
		logging.error("backing process %s stopped with code: %d" %
		(self.label, return_code))
		self.backing_process_logs.close()
		try:
		result = self.backing_process_logging_future.result(
		timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
		if result:
		logging.error(
		"backing process logging thread produced an error when executing: %s"
		% str(result))
		except concurrent.futures.TimeoutError:
		logging.error(
		"backing process logging thread failed to finish on time")
		self.backing_process_logging_executor.shutdown(wait=False)

		def wait_channel_ready(self):
		future = grpc.channel_ready_future(self.grpc_channel)
		@@ -300,9 +331,9 @@ class GdHostOnlyDevice(GdDeviceBase):

		def __init__(self, grpc_port: str, grpc_root_server_port: str,
		signal_port: str, cmd: List[str], label: str,
		type_identifier: str, name: str):
		type_identifier: str, name: str, verbose_mode: bool):
		super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd,
		label, ACTS_CONTROLLER_CONFIG_NAME, name)
		label, ACTS_CONTROLLER_CONFIG_NAME, name, verbose_mode)
		# Enable LLVM code coverage output for host only tests
		self.backing_process_profraw_path = pathlib.Path(
		self.log_path_base).joinpath("%s_%s_backing_coverage.profraw" %
		@@ -425,9 +456,10 @@ class GdAndroidDevice(GdDeviceBase):

		def __init__(self, grpc_port: str, grpc_root_server_port: str,
		signal_port: str, cmd: List[str], label: str,
		type_identifier: str, name: str, serial_number: str):
		type_identifier: str, name: str, serial_number: str,
		verbose_mode: bool):
		super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd,
		label, type_identifier, name)
		label, type_identifier, name, verbose_mode)
		asserts.assert_true(serial_number,
		"serial_number must not be None nor empty")
		self.serial_number = serial_number

system/gd/cert/os_utils.py

+9 −0

Original line number	Diff line number	Diff line
		@@ -17,11 +17,20 @@
		import logging
		from pathlib import Path
		import psutil
		import re
		import subprocess
		from typing import Container
		from collections import deque


		class TerminalColor:
		RED = "\033[31;1m"
		BLUE = "\033[34;1m"
		YELLOW = "\033[33:1m"
		MAGENTA = "\033[35;1m"
		END = "\033[0m"


		def is_subprocess_alive(process, timeout_seconds=1):
		"""
		Check if a process is alive for at least timeout_seconds

system/gd/cert/run

+23 −0

Original line number	Diff line number	Diff line
		@@ -23,6 +23,7 @@ TEST_CONFIG="$ANDROID_BUILD_TOP/packages/modules/Bluetooth/system/gd/cert/androi
		TEST_FILTER="-tf $ANDROID_BUILD_TOP/packages/modules/Bluetooth/system/gd/cert/all_cert_testcases"
		CLEAN_VENV=false
		NUM_REPETITIONS="1"
		VERBOSE_MODE=false

		POSITIONAL=()
		while [[ $# -gt 0 ]]
		@@ -56,6 +57,11 @@ case $key in
		NUM_REPETITIONS="${key#*=}"
		shift # past argument
		;;
		# This will log everything to both log file and stdout
		--verbose)
		VERBOSE_MODE=true
		shift # past argument
		;;
		*) # unknown option
		POSITIONAL+=("$1") # save it in an array for later
		shift # past argument
		@@ -111,6 +117,23 @@ if [[ $? -ne 0 ]] ; then
		exit 1
		fi

		if [ "$VERBOSE_MODE" == true ] ; then
		TEMP_CONFIG=/tmp/temp_acts_config.json
		cat $TEST_CONFIG \| $CERT_TEST_VENV/bin/python -c "
		import sys
		import json
		from acts import keys
		config = json.load(sys.stdin)
		config['verbose_mode'] = True
		print(json.dumps(config))
		" > $TEMP_CONFIG
		TEST_CONFIG=$TEMP_CONFIG
		if [[ $? -ne 0 ]] ; then
		echo "Setup failed as verbose mode is chosen but cannot be enabled"
		exit 1
		fi
		fi

		for n in $(seq $NUM_REPETITIONS); do
		$CERT_TEST_VENV/bin/python $CERT_TEST_VENV/bin/act.py \
		-c $TEST_CONFIG \