diff --git a/avatar/metrics/trace.py b/avatar/metrics/trace.py index 85f5249..409633c 100644 --- a/avatar/metrics/trace.py +++ b/avatar/metrics/trace.py @@ -52,8 +52,8 @@ def next_id() -> int: def hook_test(test: BaseTestClass, devices: PandoraDevices) -> None: global packets - original_teardown_class = test.__class__.teardown_class - original_setup_test = test.__class__.setup_test + original_teardown_class = test.teardown_class + original_setup_test = test.setup_test def teardown_class(self: BaseTestClass) -> None: output_path: str = test.current_test_info.output_path # type: ignore @@ -65,7 +65,7 @@ def teardown_class(self: BaseTestClass) -> None: f.write(f"{packet}") f.write("----------\n") - original_teardown_class(self) + original_teardown_class() def setup_test(self: BaseTestClass) -> None: global genesis @@ -92,10 +92,10 @@ def setup_test(self: BaseTestClass) -> None: ) packets.append(TracePacket(track_descriptor=descriptor)) - original_setup_test(self) + original_setup_test() - test.__class__.teardown_class = types.MethodType(teardown_class, test) - test.__class__.setup_test = types.MethodType(setup_test, test) + test.teardown_class = types.MethodType(teardown_class, test) + test.setup_test = types.MethodType(setup_test, test) class AsTrace(Protocol): @@ -121,12 +121,15 @@ def __init__(self, device: PandoraClient, name: Union[bytes, str], message: Any) device.log.info(f"{self}") - def __str__(self) -> str: + def pretty(self) -> str: name_pretty = self.name[1:].replace('/', '.') if self.message is None: return f"%{self.id} {name_pretty}" message_pretty, _ = debug_message(self.message) - return f"%{self.id} {name_pretty}({message_pretty})" + return f"{name_pretty}({message_pretty})" + + def __str__(self) -> str: + return f"{str2color('╭──', self.id)} {self.pretty()}" def output(self, message: Any) -> None: self.events.append(CallOutput(self, message)) @@ -169,7 +172,7 @@ def __init__(self, callsite: Callsite, message: Any) -> None: callsite.device.log.info(f"{self}") def __str__(self) -> str: - return "└── " + self.stringify('->') + return f"{str2color('╰──', self.callsite.id)} {self.stringify('──→')}" def as_trace(self) -> TracePacket: return TracePacket( @@ -189,12 +192,15 @@ def as_trace(self) -> TracePacket: def stringify(self, direction: str) -> str: message_pretty = "" if self.message is None else debug_message(self.message)[0] - return f"[{(self.at - self.callsite.at) / 1000000000:.3f}s] {self.callsite} {direction} ({message_pretty})" + return ( + str2color(f"[{(self.at - self.callsite.at) / 1000000000:.3f}s]", self.callsite.id) + + f" {self.callsite.pretty()} {str2color(direction, self.callsite.id)} ({message_pretty})" + ) class CallOutput(CallEvent): def __str__(self) -> str: - return "├── " + self.stringify('->') + return f"{str2color('├──', self.callsite.id)} {self.stringify('──→')}" def as_trace(self) -> TracePacket: return super().as_trace() @@ -202,7 +208,7 @@ def as_trace(self) -> TracePacket: class CallInput(CallEvent): def __str__(self) -> str: - return "├── " + self.stringify('<-') + return f"{str2color('├──', self.callsite.id)} {self.stringify('←──')}" def as_trace(self) -> TracePacket: return super().as_trace() @@ -210,7 +216,7 @@ def as_trace(self) -> TracePacket: class CallEnd(CallEvent): def __str__(self) -> str: - return "└── " + self.stringify('->') + return f"{str2color('╰──', self.callsite.id)} {self.stringify('──→')}" def as_trace(self) -> TracePacket: return TracePacket( @@ -268,3 +274,11 @@ def debug_message(msg: message.Message) -> Tuple[Dict[str, Any], List[DebugAnnot json[f.name] = json_entry dbga.append(DebugAnnotation(name=f.name, **dbga_entry)) return json, dbga + + +def str2color(s: str, id: int) -> str: + CSI = "\x1b[" + CSI_RESET = CSI + "0m" + CSI_BOLD = CSI + "1m" + color = ((id * 10) % (230 - 17)) + 17 + return CSI + ("1;38;5;%dm" % color) + CSI_BOLD + s + CSI_RESET diff --git a/avatar/pandora_client.py b/avatar/pandora_client.py index f0f9e58..60689aa 100644 --- a/avatar/pandora_client.py +++ b/avatar/pandora_client.py @@ -184,7 +184,7 @@ def process(self, msg: str, kwargs: MutableMapping[str, Any]) -> Tuple[str, Muta client = self.extra['client'] assert isinstance(client, PandoraClient) addr = ':'.join([f'{x:02X}' for x in client.address[4:]]) - return (f'[{client.name}:{addr}] {msg}', kwargs) + return (f'[{client.name:<8}:{addr}] {msg}', kwargs) class BumblePandoraClient(PandoraClient): diff --git a/avatar/pandora_server.py b/avatar/pandora_server.py index 4fd56fb..be5e8b2 100644 --- a/avatar/pandora_server.py +++ b/avatar/pandora_server.py @@ -19,7 +19,11 @@ import avatar.aio import grpc import grpc.aio +import logging +import os import portpicker +import re +import shlex import threading import types @@ -110,6 +114,8 @@ class AndroidPandoraServer(PandoraServer[AndroidDevice]): _instrumentation: Optional[threading.Thread] = None _port: int + _logger: logging.Logger + _handler: logging.Handler def start(self) -> PandoraClient: """Sets up and starts the Pandora server on the Android device.""" @@ -130,6 +136,31 @@ def start(self) -> PandoraClient: self._instrumentation.start() self.device.adb.forward([f'tcp:{self._port}', f'tcp:{ANDROID_SERVER_GRPC_PORT}']) # type: ignore + # Forward all logging to ADB logs + adb = self.device.adb + + class AdbLoggingHandler(logging.Handler): + def emit(self, record: logging.LogRecord) -> None: + if record.levelno <= logging.DEBUG: + return + ansi_escape = re.compile(r'\x1B(?:[@-Z\\-_]|\[[0-?]*[ -/]*[@-~])') + msg = self.format(record) + msg = ansi_escape.sub('', msg) + level = { + logging.FATAL: 'f', + logging.ERROR: 'e', + logging.WARN: 'w', + logging.INFO: 'i', + logging.DEBUG: 'd', + logging.NOTSET: 'd', + }[record.levelno] + for msg in msg.splitlines(): + os.system(f'adb -s {adb.serial} shell "log -t Avatar -p {level} {shlex.quote(msg)}"') + + self._logger = logging.getLogger() + self._handler = AdbLoggingHandler() + self._logger.addHandler(self._handler) + return PandoraClient(f'localhost:{self._port}', 'android') def stop(self) -> None: @@ -141,6 +172,9 @@ def stop(self) -> None: 'shell', f'am force-stop {ANDROID_SERVER_PACKAGE}', shell=False, timeout=None, stderr=None ) + # Remove ADB logging handler + self._logger.removeHandler(self._handler) + self.device.adb.forward(['--remove', f'tcp:{self._port}']) # type: ignore self._instrumentation.join() self._instrumentation = None