android: forward all logs to adb logs

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,28 +192,31 @@ 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()
 
 
 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()
 
 
 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

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):

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