gh-144415: Android testbed fixes (GH-142912)

Modifies handling of `.gz` files in Android app payloads, and ensures that
when the Android testbed streams logs, stream flushes aren't treated as
newlines. This improves the output of test suites that use "one dot per test"
progress indicators.
(cherry picked from commit cb1dc91)

Co-authored-by: Malcolm Smith <smith@chaquo.com>

Author: mhsmith

Android/android.py

@@ -15,6 +15,7 @@
 from asyncio import wait_for
 from contextlib import asynccontextmanager
 from datetime import datetime, timezone
+from enum import IntEnum, auto
 from glob import glob
 from os.path import abspath, basename, relpath
 from pathlib import Path
@@ -61,6 +62,19 @@
 hidden_output = []
 
 
+# Based on android/log.h in the NDK.
+class LogPriority(IntEnum):
+    UNKNOWN = 0
+    DEFAULT = auto()
+    VERBOSE = auto()
+    DEBUG = auto()
+    INFO = auto()
+    WARN = auto()
+    ERROR = auto()
+    FATAL = auto()
+    SILENT = auto()
+
+
 def log_verbose(context, line, stream=sys.stdout):
     if context.verbose:
         stream.write(line)
@@ -505,47 +519,47 @@ async def logcat_task(context, initial_devices):
     pid = await wait_for(find_pid(serial), startup_timeout)
 
     # `--pid` requires API level 24 or higher.
-    args = [adb, "-s", serial, "logcat", "--pid", pid,  "--format", "tag"]
+    #
+    # `--binary` mode is used in order to detect which messages end with a
+    # newline, which most of the other modes don't indicate (except `--format
+    # long`). For example, every time pytest runs a test, it prints a "." and
+    # flushes the stream. Each "." becomes a separate log message, but we should
+    # show them all on the same line.
+    args = [adb, "-s", serial, "logcat", "--pid", pid,  "--binary"]
     logcat_started = False
     async with async_process(
-        *args, stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
+        *args, stdout=subprocess.PIPE, stderr=None
     ) as process:
-        while line := (await process.stdout.readline()).decode(*DECODE_ARGS):
-            if match := re.fullmatch(r"([A-Z])/(.*)", line, re.DOTALL):
+        while True:
+            try:
+                priority, tag, message = await read_logcat(process.stdout)
                 logcat_started = True
-                level, message = match.groups()
-            else:
-                # If the regex doesn't match, this is either a logcat startup
-                # error, or the second or subsequent line of a multi-line
-                # message. Python won't produce multi-line messages, but other
-                # components might.
-                level, message = None, line
+            except asyncio.IncompleteReadError:
+                break
 
             # Exclude high-volume messages which are rarely useful.
             if context.verbose < 2 and "from python test_syslog" in message:
                 continue
 
             # Put high-level messages on stderr so they're highlighted in the
             # buildbot logs. This will include Python's own stderr.
-            stream = (
-                sys.stderr
-                if level in ["W", "E", "F"]  # WARNING, ERROR, FATAL (aka ASSERT)
-                else sys.stdout
-            )
-
-            # To simplify automated processing of the output, e.g. a buildbot
-            # posting a failure notice on a GitHub PR, we strip the level and
-            # tag indicators from Python's stdout and stderr.
-            for prefix in ["python.stdout: ", "python.stderr: "]:
-                if message.startswith(prefix):
-                    global python_started
-                    python_started = True
-                    stream.write(message.removeprefix(prefix))
-                    break
+            stream = sys.stderr if priority >= LogPriority.WARN else sys.stdout
+
+            # The app's stdout and stderr should be passed through transparently
+            # to our own corresponding streams.
+            if tag in ["python.stdout", "python.stderr"]:
+                global python_started
+                python_started = True
+                stream.write(message)
+                stream.flush()
             else:
                 # Non-Python messages add a lot of noise, but they may
-                # sometimes help explain a failure.
-                log_verbose(context, line, stream)
+                # sometimes help explain a failure. Format them in the same way
+                # as `logcat --format tag`.
+                formatted = f"{priority.name[0]}/{tag}: {message}"
+                if not formatted.endswith("\n"):
+                    formatted += "\n"
+                log_verbose(context, formatted, stream)
 
         # If the device disconnects while logcat is running, which always
         # happens in --managed mode, some versions of adb return non-zero.
@@ -556,6 +570,44 @@ async def logcat_task(context, initial_devices):
             raise CalledProcessError(status, args)
 
 
+# Read one binary log message from the given StreamReader. The message format is
+# described at https://android.stackexchange.com/a/74660. All supported versions
+# of Android use format version 2 or later.
+async def read_logcat(stream):
+    async def read_bytes(size):
+        return await stream.readexactly(size)
+
+    async def read_int(size):
+        return int.from_bytes(await read_bytes(size), "little")
+
+    payload_len = await read_int(2)
+    if payload_len < 2:
+        # 1 byte for priority, 1 byte for null terminator of tag.
+        raise ValueError(f"payload length {payload_len} is too short")
+
+    header_len = await read_int(2)
+    if header_len < 4:
+        raise ValueError(f"header length {header_len} is too short")
+    await read_bytes(header_len - 4)  # Ignore other header fields.
+
+    priority_int = await read_int(1)
+    try:
+        priority = LogPriority(priority_int)
+    except ValueError:
+        priority = LogPriority.UNKNOWN
+
+    payload_fields = (await read_bytes(payload_len - 1)).split(b"\0")
+    if len(payload_fields) < 2:
+        raise ValueError(
+            f"payload {payload!r} does not contain at least 2 "
+            f"null-separated fields"
+        )
+    tag, message, *_ = [
+        field.decode(*DECODE_ARGS) for field in payload_fields
+    ]
+    return priority, tag, message
+
+
 def stop_app(serial):
     run([adb, "-s", serial, "shell", "am", "force-stop", APP_ID], log=False)
 

Android/testbed/app/build.gradle.kts

@@ -94,10 +94,13 @@ android {
         }
 
         // This controls the API level of the maxVersion managed emulator, which is used
-        // by CI and cibuildwheel. 34 takes up too much disk space (#142289), 35 has
-        // issues connecting to the internet (#142387), and 36 and later are not
-        // available as aosp_atd images yet.
-        targetSdk = 33
+        // by CI and cibuildwheel.
+        //  * 33 has excessive buffering in the logcat client
+        //    (https://cs.android.com/android/_/android/platform/system/logging/+/d340721894f223327339010df59b0ac514308826).
+        //  * 34 consumes too much disk space on GitHub Actions (#142289).
+        //  * 35 has issues connecting to the internet (#142387).
+        //  * 36 and later are not available as aosp_atd images yet.
+        targetSdk = 32
 
         versionCode = 1
         versionName = "1.0"
@@ -130,9 +133,10 @@ android {
         path("src/main/c/CMakeLists.txt")
     }
 
-    // Set this property to something non-empty, otherwise it'll use the default
-    // list, which ignores asset directories beginning with an underscore.
-    aaptOptions.ignoreAssetsPattern = ".git"
+    // Set this property to something nonexistent but non-empty. Otherwise it'll use the
+    // default list, which ignores asset directories beginning with an underscore, and
+    // maybe also other files required by tests.
+    aaptOptions.ignoreAssetsPattern = "android-testbed-dont-ignore-anything"
 
     compileOptions {
         sourceCompatibility = JavaVersion.VERSION_1_8
@@ -234,6 +238,12 @@ androidComponents.onVariants { variant ->
                     from(cwd)
                 }
             }
+
+            // A filename ending with .gz will be automatically decompressed
+            // while building the APK. Avoid this by adding a dash to the end,
+            // and add an extra dash to any filenames that already end with one.
+            // This will be undone in MainActivity.kt.
+            rename(""".*(\.gz|-)""", "$0-")
         }
     }
 

Android/testbed/app/src/main/java/org/python/testbed/MainActivity.kt

@@ -80,7 +80,9 @@ class PythonTestRunner(val context: Context) {
                 continue
             }
             input.use {
-                File(targetSubdir, name).outputStream().use { output ->
+                // Undo the .gz workaround from build.gradle.kts.
+                val outputName = name.replace(Regex("""(.*)-"""), "$1")
+                File(targetSubdir, outputName).outputStream().use { output ->
                     input.copyTo(output)
                 }
             }

Lib/_android_support.py

@@ -168,6 +168,13 @@ def write(self, prio, tag, message):
         # message.
         message = message.replace(b"\x00", b"\xc0\x80")
 
+        # On API level 30 and higher, Logcat will strip any number of leading
+        # newlines. This is visible in all `logcat` modes, even --binary. Work
+        # around this by adding a leading space, which shouldn't make any
+        # difference to the log's usability.
+        if message.startswith(b"\n"):
+            message = b" " + message
+
         with self._lock:
             now = time()
             self._bucket_level += (

Lib/test/test_android.py

@@ -1,5 +1,4 @@
 import io
-import platform
 import queue
 import re
 import subprocess
@@ -17,8 +16,6 @@
 if sys.platform != "android":
     raise unittest.SkipTest("Android-specific")
 
-api_level = platform.android_ver().api_level
-
 # (name, level, fileno)
 STREAM_INFO = [("stdout", "I", 1), ("stderr", "W", 2)]
 
@@ -179,14 +176,18 @@ def write(s, lines=None, *, write_len=None):
 
                 # Multi-line messages. Avoid identical consecutive lines, as
                 # they may activate "chatty" filtering and break the tests.
-                write("\nx", [""])
+                #
+                # Additional spaces will appear in the output where necessary to
+                # protect leading newlines.
+                write("\nx", [" "])
                 write("\na\n", ["x", "a"])
-                write("\n", [""])
+                write("\n", [" "])
+                write("\n\n", [" ", " "])
                 write("b\n", ["b"])
-                write("c\n\n", ["c", ""])
+                write("c\n\n", ["c", " "])
                 write("d\ne", ["d"])
                 write("xx", [])
-                write("f\n\ng", ["exxf", ""])
+                write("f\n\ng", ["exxf", " "])
                 write("\n", ["g"])
 
                 # Since this is a line-based logging system, line buffering
@@ -197,15 +198,16 @@ def write(s, lines=None, *, write_len=None):
                 # However, buffering can be turned off completely if you want a
                 # flush after every write.
                 with self.reconfigure(stream, write_through=True):
-                    write("\nx", ["", "x"])
-                    write("\na\n", ["", "a"])
-                    write("\n", [""])
+                    write("\nx", [" ", "x"])
+                    write("\na\n", [" ", "a"])
+                    write("\n", [" "])
+                    write("\n\n", [" ", " "])
                     write("b\n", ["b"])
-                    write("c\n\n", ["c", ""])
+                    write("c\n\n", ["c", " "])
                     write("d\ne", ["d", "e"])
                     write("xx", ["xx"])
-                    write("f\n\ng", ["f", "", "g"])
-                    write("\n", [""])
+                    write("f\n\ng", ["f", " ", "g"])
+                    write("\n", [" "])
 
                 # "\r\n" should be translated into "\n".
                 write("hello\r\n", ["hello"])
@@ -325,19 +327,16 @@ def write(b, lines=None, *, write_len=None):
                 # currently use `logcat -v tag`, which shows each line as if it
                 # was a separate log entry, but strips a single trailing
                 # newline.
-                #
-                # On newer versions of Android, all three of the above tools (or
-                # maybe Logcat itself) will also strip any number of leading
-                # newlines.
-                write(b"\nx", ["", "x"] if api_level < 30 else ["x"])
-                write(b"\na\n", ["", "a"] if api_level < 30 else ["a"])
-                write(b"\n", [""])
+                write(b"\nx", [" ", "x"])
+                write(b"\na\n", [" ", "a"])
+                write(b"\n", [" "])
+                write(b"\n\n", [" ", ""])
                 write(b"b\n", ["b"])
                 write(b"c\n\n", ["c", ""])
                 write(b"d\ne", ["d", "e"])
                 write(b"xx", ["xx"])
                 write(b"f\n\ng", ["f", "", "g"])
-                write(b"\n", [""])
+                write(b"\n", [" "])
 
                 # "\r\n" should be translated into "\n".
                 write(b"hello\r\n", ["hello"])

Misc/NEWS.d/next/Tests/2026-02-03-07-57-24.gh-issue-144415.U3L15r.rst

@@ -0,0 +1,3 @@
+The Android testbed now distinguishes between stdout/stderr messages which
+were triggered by a newline, and those triggered by a manual call to
+``flush``. This fixes logging of progress indicators and similar content.