• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1import io
2import sys
3from threading import RLock
4from time import sleep, time
5
6# The maximum length of a log message in bytes, including the level marker and
7# tag, is defined as LOGGER_ENTRY_MAX_PAYLOAD at
8# https://cs.android.com/android/platform/superproject/+/android-14.0.0_r1:system/logging/liblog/include/log/log.h;l=71.
9# Messages longer than this will be be truncated by logcat. This limit has already
10# been reduced at least once in the history of Android (from 4076 to 4068 between
11# API level 23 and 26), so leave some headroom.
12MAX_BYTES_PER_WRITE = 4000
13
14# UTF-8 uses a maximum of 4 bytes per character, so limiting text writes to this
15# size ensures that we can always avoid exceeding MAX_BYTES_PER_WRITE.
16# However, if the actual number of bytes per character is smaller than that,
17# then we may still join multiple consecutive text writes into binary
18# writes containing a larger number of characters.
19MAX_CHARS_PER_WRITE = MAX_BYTES_PER_WRITE // 4
20
21
22# When embedded in an app on current versions of Android, there's no easy way to
23# monitor the C-level stdout and stderr. The testbed comes with a .c file to
24# redirect them to the system log using a pipe, but that wouldn't be convenient
25# or appropriate for all apps. So we redirect at the Python level instead.
26def init_streams(android_log_write, stdout_prio, stderr_prio):
27    if sys.executable:
28        return  # Not embedded in an app.
29
30    global logcat
31    logcat = Logcat(android_log_write)
32
33    sys.stdout = TextLogStream(
34        stdout_prio, "python.stdout", sys.stdout.fileno())
35    sys.stderr = TextLogStream(
36        stderr_prio, "python.stderr", sys.stderr.fileno())
37
38
39class TextLogStream(io.TextIOWrapper):
40    def __init__(self, prio, tag, fileno=None, **kwargs):
41        # The default is surrogateescape for stdout and backslashreplace for
42        # stderr, but in the context of an Android log, readability is more
43        # important than reversibility.
44        kwargs.setdefault("encoding", "UTF-8")
45        kwargs.setdefault("errors", "backslashreplace")
46
47        super().__init__(BinaryLogStream(prio, tag, fileno), **kwargs)
48        self._lock = RLock()
49        self._pending_bytes = []
50        self._pending_bytes_count = 0
51
52    def __repr__(self):
53        return f"<TextLogStream {self.buffer.tag!r}>"
54
55    def write(self, s):
56        if not isinstance(s, str):
57            raise TypeError(
58                f"write() argument must be str, not {type(s).__name__}")
59
60        # In case `s` is a str subclass that writes itself to stdout or stderr
61        # when we call its methods, convert it to an actual str.
62        s = str.__str__(s)
63
64        # We want to emit one log message per line wherever possible, so split
65        # the string into lines first. Note that "".splitlines() == [], so
66        # nothing will be logged for an empty string.
67        with self._lock:
68            for line in s.splitlines(keepends=True):
69                while line:
70                    chunk = line[:MAX_CHARS_PER_WRITE]
71                    line = line[MAX_CHARS_PER_WRITE:]
72                    self._write_chunk(chunk)
73
74        return len(s)
75
76    # The size and behavior of TextIOWrapper's buffer is not part of its public
77    # API, so we handle buffering ourselves to avoid truncation.
78    def _write_chunk(self, s):
79        b = s.encode(self.encoding, self.errors)
80        if self._pending_bytes_count + len(b) > MAX_BYTES_PER_WRITE:
81            self.flush()
82
83        self._pending_bytes.append(b)
84        self._pending_bytes_count += len(b)
85        if (
86            self.write_through
87            or b.endswith(b"\n")
88            or self._pending_bytes_count > MAX_BYTES_PER_WRITE
89        ):
90            self.flush()
91
92    def flush(self):
93        with self._lock:
94            self.buffer.write(b"".join(self._pending_bytes))
95            self._pending_bytes.clear()
96            self._pending_bytes_count = 0
97
98    # Since this is a line-based logging system, line buffering cannot be turned
99    # off, i.e. a newline always causes a flush.
100    @property
101    def line_buffering(self):
102        return True
103
104
105class BinaryLogStream(io.RawIOBase):
106    def __init__(self, prio, tag, fileno=None):
107        self.prio = prio
108        self.tag = tag
109        self._fileno = fileno
110
111    def __repr__(self):
112        return f"<BinaryLogStream {self.tag!r}>"
113
114    def writable(self):
115        return True
116
117    def write(self, b):
118        if type(b) is not bytes:
119            try:
120                b = bytes(memoryview(b))
121            except TypeError:
122                raise TypeError(
123                    f"write() argument must be bytes-like, not {type(b).__name__}"
124                ) from None
125
126        # Writing an empty string to the stream should have no effect.
127        if b:
128            logcat.write(self.prio, self.tag, b)
129        return len(b)
130
131    # This is needed by the test suite --timeout option, which uses faulthandler.
132    def fileno(self):
133        if self._fileno is None:
134            raise io.UnsupportedOperation("fileno")
135        return self._fileno
136
137
138# When a large volume of data is written to logcat at once, e.g. when a test
139# module fails in --verbose3 mode, there's a risk of overflowing logcat's own
140# buffer and losing messages. We avoid this by imposing a rate limit using the
141# token bucket algorithm, based on a conservative estimate of how fast `adb
142# logcat` can consume data.
143MAX_BYTES_PER_SECOND = 1024 * 1024
144
145# The logcat buffer size of a device can be determined by running `logcat -g`.
146# We set the token bucket size to half of the buffer size of our current minimum
147# API level, because other things on the system will be producing messages as
148# well.
149BUCKET_SIZE = 128 * 1024
150
151# https://cs.android.com/android/platform/superproject/+/android-14.0.0_r1:system/logging/liblog/include/log/log_read.h;l=39
152PER_MESSAGE_OVERHEAD = 28
153
154
155class Logcat:
156    def __init__(self, android_log_write):
157        self.android_log_write = android_log_write
158        self._lock = RLock()
159        self._bucket_level = 0
160        self._prev_write_time = time()
161
162    def write(self, prio, tag, message):
163        # Encode null bytes using "modified UTF-8" to avoid them truncating the
164        # message.
165        message = message.replace(b"\x00", b"\xc0\x80")
166
167        with self._lock:
168            now = time()
169            self._bucket_level += (
170                (now - self._prev_write_time) * MAX_BYTES_PER_SECOND)
171
172            # If the bucket level is still below zero, the clock must have gone
173            # backwards, so reset it to zero and continue.
174            self._bucket_level = max(0, min(self._bucket_level, BUCKET_SIZE))
175            self._prev_write_time = now
176
177            self._bucket_level -= PER_MESSAGE_OVERHEAD + len(tag) + len(message)
178            if self._bucket_level < 0:
179                sleep(-self._bucket_level / MAX_BYTES_PER_SECOND)
180
181            self.android_log_write(prio, tag, message)
182