11import io
22import sys
3-
3+ from threading import RLock
4+ from time import sleep , time
45
56# The maximum length of a log message in bytes, including the level marker and
6- # tag, is defined as LOGGER_ENTRY_MAX_PAYLOAD in
7- # platform/system/logging/liblog/include/log/log.h. As of API level 30, messages
8- # longer than this will be be truncated by logcat. This limit has already been
9- # reduced at least once in the history of Android (from 4076 to 4068 between API
10- # level 23 and 26), so leave some headroom.
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.
1112MAX_BYTES_PER_WRITE = 4000
1213
1314# UTF-8 uses a maximum of 4 bytes per character, so limiting text writes to this
14- # size ensures that TextIOWrapper can always avoid exceeding MAX_BYTES_PER_WRITE.
15+ # size ensures that we can always avoid exceeding MAX_BYTES_PER_WRITE.
1516# However, if the actual number of bytes per character is smaller than that,
16- # then TextIOWrapper may still join multiple consecutive text writes into binary
17+ # then we may still join multiple consecutive text writes into binary
1718# writes containing a larger number of characters.
1819MAX_CHARS_PER_WRITE = MAX_BYTES_PER_WRITE // 4
1920
@@ -26,18 +27,22 @@ def init_streams(android_log_write, stdout_prio, stderr_prio):
2627 if sys .executable :
2728 return # Not embedded in an app.
2829
30+ global logcat
31+ logcat = Logcat (android_log_write )
32+
2933 sys .stdout = TextLogStream (
30- android_log_write , stdout_prio , "python.stdout" , errors = sys .stdout .errors )
34+ stdout_prio , "python.stdout" , errors = sys .stdout .errors )
3135 sys .stderr = TextLogStream (
32- android_log_write , stderr_prio , "python.stderr" , errors = sys .stderr .errors )
36+ stderr_prio , "python.stderr" , errors = sys .stderr .errors )
3337
3438
3539class TextLogStream (io .TextIOWrapper ):
36- def __init__ (self , android_log_write , prio , tag , ** kwargs ):
40+ def __init__ (self , prio , tag , ** kwargs ):
3741 kwargs .setdefault ("encoding" , "UTF-8" )
38- kwargs .setdefault ("line_buffering" , True )
39- super ().__init__ (BinaryLogStream (android_log_write , prio , tag ), ** kwargs )
40- self ._CHUNK_SIZE = MAX_BYTES_PER_WRITE
42+ super ().__init__ (BinaryLogStream (prio , tag ), ** kwargs )
43+ self ._lock = RLock ()
44+ self ._pending_bytes = []
45+ self ._pending_bytes_count = 0
4146
4247 def __repr__ (self ):
4348 return f"<TextLogStream { self .buffer .tag !r}
@@ -52,19 +57,48 @@ def write(self, s):
5257 s = str .__str__ (s )
5358
5459 # We want to emit one log message per line wherever possible, so split
55- # the string before sending it to the superclass. Note that
56- # "".splitlines() == [], so nothing will be logged for an empty string.
57- for line in s .splitlines (keepends = True ):
58- while line :
59- super ().write (line [:MAX_CHARS_PER_WRITE ])
60- line = line [MAX_CHARS_PER_WRITE :]
60+ # the string into lines first. Note that "".splitlines() == [], so
61+ # nothing will be logged for an empty string.
62+ with self ._lock :
63+ for line in s .splitlines (keepends = True ):
64+ while line :
65+ chunk = line [:MAX_CHARS_PER_WRITE ]
66+ line = line [MAX_CHARS_PER_WRITE :]
67+ self ._write_chunk (chunk )
6168
6269 return len (s )
6370
71+ # The size and behavior of TextIOWrapper's buffer is not part of its public
72+ # API, so we handle buffering ourselves to avoid truncation.
73+ def _write_chunk (self , s ):
74+ b = s .encode (self .encoding , self .errors )
75+ if self ._pending_bytes_count + len (b ) > MAX_BYTES_PER_WRITE :
76+ self .flush ()
77+
78+ self ._pending_bytes .append (b )
79+ self ._pending_bytes_count += len (b )
80+ if (
81+ self .write_through
82+ or b .endswith (b"\n " )
83+ or self ._pending_bytes_count > MAX_BYTES_PER_WRITE
84+ ):
85+ self .flush ()
86+
87+ def flush (self ):
88+ with self ._lock :
89+ self .buffer .write (b"" .join (self ._pending_bytes ))
90+ self ._pending_bytes .clear ()
91+ self ._pending_bytes_count = 0
92+
93+ # Since this is a line-based logging system, line buffering cannot be turned
94+ # off, i.e. a newline always causes a flush.
95+ @property
96+ def line_buffering (self ):
97+ return True
98+
6499
65100class BinaryLogStream (io .RawIOBase ):
66- def __init__ (self , android_log_write , prio , tag ):
67- self .android_log_write = android_log_write
101+ def __init__ (self , prio , tag ):
68102 self .prio = prio
69103 self .tag = tag
70104
@@ -85,10 +119,48 @@ def write(self, b):
85119
86120 # Writing an empty string to the stream should have no effect.
87121 if b :
88- # Encode null bytes using "modified UTF-8" to avoid truncating the
89- # message. This should not affect the return value, as the caller
90- # may be expecting it to match the length of the input.
91- self .android_log_write (self .prio , self .tag ,
92- b .replace (b"\x00 " , b"\xc0 \x80 " ))
93-
122+ logcat .write (self .prio , self .tag , b )
94123 return len (b )
124+
125+
126+ # When a large volume of data is written to logcat at once, e.g. when a test
127+ # module fails in --verbose3 mode, there's a risk of overflowing logcat's own
128+ # buffer and losing messages. We avoid this by imposing a rate limit using the
129+ # token bucket algorithm, based on a conservative estimate of how fast `adb
130+ # logcat` can consume data.
131+ MAX_BYTES_PER_SECOND = 1024 * 1024
132+
133+ # The logcat buffer size of a device can be determined by running `logcat -g`.
134+ # We set the token bucket size to half of the buffer size of our current minimum
135+ # API level, because other things on the system will be producing messages as
136+ # well.
137+ BUCKET_SIZE = 128 * 1024
138+
139+ # https://cs.android.com/android/platform/superproject/+/android-14.0.0_r1:system/logging/liblog/include/log/log_read.h;l=39
140+ PER_MESSAGE_OVERHEAD = 28
141+
142+
143+ class Logcat :
144+ def __init__ (self , android_log_write ):
145+ self .android_log_write = android_log_write
146+ self ._lock = RLock ()
147+ self ._bucket_level = 0
148+ self ._prev_write_time = time ()
149+
150+ def write (self , prio , tag , message ):
151+ # Encode null bytes using "modified UTF-8" to avoid them truncating the
152+ # message.
153+ message = message .replace (b"\x00 " , b"\xc0 \x80 " )
154+
155+ with self ._lock :
156+ now = time ()
157+ self ._bucket_level += (
158+ (now - self ._prev_write_time ) * MAX_BYTES_PER_SECOND )
159+ self ._bucket_level = min (self ._bucket_level , BUCKET_SIZE )
160+ self ._prev_write_time = now
161+
162+ self ._bucket_level -= PER_MESSAGE_OVERHEAD + len (tag ) + len (message )
163+ if self ._bucket_level < 0 :
164+ sleep (- self ._bucket_level / MAX_BYTES_PER_SECOND )
165+
166+ self .android_log_write (prio , tag , message )
0 commit comments