Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit0dd89a7

Browse files
[3.13]gh-116622: Android logging fixes (GH-122698) (#122719)
gh-116622: Android logging fixes (GH-122698)Modifies the handling of stdout/stderr redirection on Android to accomodatethe rate and buffer size limits imposed by Android's logging infrastructure.(cherry picked from commitb0c48b8)Co-authored-by: Malcolm Smith <smith@chaquo.com>
1 parent69cf92f commit0dd89a7

File tree

3 files changed

+213
-48
lines changed

3 files changed

+213
-48
lines changed

‎Lib/_android_support.py

Lines changed: 100 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -1,19 +1,20 @@
11
importio
22
importsys
3-
3+
fromthreadingimportRLock
4+
fromtimeimportsleep,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_PAYLOADin
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_PAYLOADat
8+
#https://cs.android.com/android/platform/superproject/+/android-14.0.0_r1:system/logging/liblog/include/log/log.h;l=71.
9+
#Messageslonger than this will be be truncated by logcat. This limit has already
10+
#beenreduced at least once in the history of Android (from 4076 to 4068 between
11+
#APIlevel 23 and 26), so leave some headroom.
1112
MAX_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 thatTextIOWrapper can always avoid exceeding MAX_BYTES_PER_WRITE.
15+
# size ensures thatwe can always avoid exceeding MAX_BYTES_PER_WRITE.
1516
# However, if the actual number of bytes per character is smaller than that,
16-
# thenTextIOWrapper may still join multiple consecutive text writes into binary
17+
# thenwe may still join multiple consecutive text writes into binary
1718
# writes containing a larger number of characters.
1819
MAX_CHARS_PER_WRITE=MAX_BYTES_PER_WRITE//4
1920

@@ -26,18 +27,22 @@ def init_streams(android_log_write, stdout_prio, stderr_prio):
2627
ifsys.executable:
2728
return# Not embedded in an app.
2829

30+
globallogcat
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

3539
classTextLogStream(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
returnf"<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-
forlineins.splitlines(keepends=True):
58-
whileline:
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+
withself._lock:
63+
forlineins.splitlines(keepends=True):
64+
whileline:
65+
chunk=line[:MAX_CHARS_PER_WRITE]
66+
line=line[MAX_CHARS_PER_WRITE:]
67+
self._write_chunk(chunk)
6168

6269
returnlen(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+
ifself._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+
orb.endswith(b"\n")
83+
orself._pending_bytes_count>MAX_BYTES_PER_WRITE
84+
):
85+
self.flush()
86+
87+
defflush(self):
88+
withself._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+
defline_buffering(self):
97+
returnTrue
98+
6499

65100
classBinaryLogStream(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
ifb:
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
returnlen(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+
classLogcat:
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+
defwrite(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+
withself._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+
ifself._bucket_level<0:
164+
sleep(-self._bucket_level/MAX_BYTES_PER_SECOND)
165+
166+
self.android_log_write(prio,tag,message)

‎Lib/test/test_android.py

Lines changed: 112 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,17 @@
1+
importio
12
importplatform
23
importqueue
34
importre
45
importsubprocess
56
importsys
67
importunittest
8+
from_android_supportimportTextLogStream
79
fromarrayimportarray
8-
fromcontextlibimportcontextmanager
10+
fromcontextlibimportExitStack,contextmanager
911
fromthreadingimportThread
1012
fromtest.supportimportLOOPBACK_TIMEOUT
11-
fromtimeimporttime
13+
fromtimeimportsleep,time
14+
fromunittest.mockimportpatch
1215

1316

1417
ifsys.platform!="android":
@@ -81,18 +84,39 @@ def unbuffered(self, stream):
8184
finally:
8285
stream.reconfigure(write_through=False)
8386

87+
# In --verbose3 mode, sys.stdout and sys.stderr are captured, so we can't
88+
# test them directly. Detect this mode and use some temporary streams with
89+
# the same properties.
90+
defstream_context(self,stream_name,level):
91+
# https://developer.android.com/ndk/reference/group/logging
92+
prio= {"I":4,"W":5}[level]
93+
94+
stack=ExitStack()
95+
stack.enter_context(self.subTest(stream_name))
96+
stream=getattr(sys,stream_name)
97+
ifisinstance(stream,io.StringIO):
98+
stack.enter_context(
99+
patch(
100+
f"sys.{stream_name}",
101+
TextLogStream(
102+
prio,f"python.{stream_name}",errors="backslashreplace"
103+
),
104+
)
105+
)
106+
returnstack
107+
84108
deftest_str(self):
85109
forstream_name,levelin [("stdout","I"), ("stderr","W")]:
86-
withself.subTest(stream=stream_name):
110+
withself.stream_context(stream_name,level):
87111
stream=getattr(sys,stream_name)
88112
tag=f"python.{stream_name}"
89113
self.assertEqual(f"<TextLogStream '{tag}'>",repr(stream))
90114

91-
self.assertTrue(stream.writable())
92-
self.assertFalse(stream.readable())
115+
self.assertIs(stream.writable(),True)
116+
self.assertIs(stream.readable(),False)
93117
self.assertEqual("UTF-8",stream.encoding)
94-
self.assertTrue(stream.line_buffering)
95-
self.assertFalse(stream.write_through)
118+
self.assertIs(stream.line_buffering,True)
119+
self.assertIs(stream.write_through,False)
96120

97121
# stderr is backslashreplace by default; stdout is configured
98122
# that way by libregrtest.main.
@@ -147,6 +171,13 @@ def write(s, lines=None, *, write_len=None):
147171
write("f\n\ng", ["exxf",""])
148172
write("\n", ["g"])
149173

174+
# Since this is a line-based logging system, line buffering
175+
# cannot be turned off, i.e. a newline always causes a flush.
176+
stream.reconfigure(line_buffering=False)
177+
self.assertIs(stream.line_buffering,True)
178+
179+
# However, buffering can be turned off completely if you want a
180+
# flush after every write.
150181
withself.unbuffered(stream):
151182
write("\nx", ["","x"])
152183
write("\na\n", ["","a"])
@@ -209,30 +240,30 @@ def __str__(self):
209240
# (MAX_BYTES_PER_WRITE).
210241
#
211242
# ASCII (1 byte per character)
212-
write(("foobar"*700)+"\n",
213-
[("foobar"*666)+"foob",# 4000 bytes
214-
"ar"+ ("foobar"*33)])# 200 bytes
243+
write(("foobar"*700)+"\n",# 4200 bytes in
244+
[("foobar"*666)+"foob",# 4000 bytes out
245+
"ar"+ ("foobar"*33)])# 200 bytes out
215246

216247
# "Full-width" digits 0-9 (3 bytes per character)
217248
s="\uff10\uff11\uff12\uff13\uff14\uff15\uff16\uff17\uff18\uff19"
218-
write((s*150)+"\n",
219-
[s*100,# 3000 bytes
220-
s*50])# 1500 bytes
249+
write((s*150)+"\n",# 4500 bytes in
250+
[s*100,# 3000 bytes out
251+
s*50])# 1500 bytes out
221252

222253
s="0123456789"
223-
write(s*200, [])
224-
write(s*150, [])
225-
write(s*51, [s*350])# 3500 bytes
226-
write("\n", [s*51])# 510 bytes
254+
write(s*200, [])# 2000 bytes in
255+
write(s*150, [])# 1500 bytes in
256+
write(s*51, [s*350])#510 bytes in,3500 bytes out
257+
write("\n", [s*51])#0 bytes in,510 bytes out
227258

228259
deftest_bytes(self):
229260
forstream_name,levelin [("stdout","I"), ("stderr","W")]:
230-
withself.subTest(stream=stream_name):
261+
withself.stream_context(stream_name,level):
231262
stream=getattr(sys,stream_name).buffer
232263
tag=f"python.{stream_name}"
233264
self.assertEqual(f"<BinaryLogStream '{tag}'>",repr(stream))
234-
self.assertTrue(stream.writable())
235-
self.assertFalse(stream.readable())
265+
self.assertIs(stream.writable(),True)
266+
self.assertIs(stream.readable(),False)
236267

237268
defwrite(b,lines=None,*,write_len=None):
238269
ifwrite_lenisNone:
@@ -330,3 +361,64 @@ def write(b, lines=None, *, write_len=None):
330361
fr"{type(obj).__name__}"
331362
):
332363
stream.write(obj)
364+
365+
deftest_rate_limit(self):
366+
# https://cs.android.com/android/platform/superproject/+/android-14.0.0_r1:system/logging/liblog/include/log/log_read.h;l=39
367+
PER_MESSAGE_OVERHEAD=28
368+
369+
# https://developer.android.com/ndk/reference/group/logging
370+
ANDROID_LOG_DEBUG=3
371+
372+
# To avoid flooding the test script output, use a different tag rather
373+
# than stdout or stderr.
374+
tag="python.rate_limit"
375+
stream=TextLogStream(ANDROID_LOG_DEBUG,tag)
376+
377+
# Make a test message which consumes 1 KB of the logcat buffer.
378+
message="Line {:03d} "
379+
message+="."* (
380+
1024-PER_MESSAGE_OVERHEAD-len(tag)-len(message.format(0))
381+
)+"\n"
382+
383+
# See _android_support.py. The default values of these parameters work
384+
# well across a wide range of devices, but we'll use smaller values to
385+
# ensure a quick and reliable test that doesn't flood the log too much.
386+
MAX_KB_PER_SECOND=100
387+
BUCKET_KB=10
388+
with (
389+
patch("_android_support.MAX_BYTES_PER_SECOND",MAX_KB_PER_SECOND*1024),
390+
patch("_android_support.BUCKET_SIZE",BUCKET_KB*1024),
391+
):
392+
# Make sure the token bucket is full.
393+
sleep(BUCKET_KB/MAX_KB_PER_SECOND)
394+
line_num=0
395+
396+
# Write BUCKET_KB messages, and return the rate at which they were
397+
# accepted in KB per second.
398+
defwrite_bucketful():
399+
nonlocalline_num
400+
start=time()
401+
max_line_num=line_num+BUCKET_KB
402+
whileline_num<max_line_num:
403+
stream.write(message.format(line_num))
404+
line_num+=1
405+
returnBUCKET_KB/ (time()-start)
406+
407+
# The first bucketful should be written with minimal delay. The
408+
# factor of 2 here is not arbitrary: it verifies that the system can
409+
# write fast enough to empty the bucket within two bucketfuls, which
410+
# the next part of the test depends on.
411+
self.assertGreater(write_bucketful(),MAX_KB_PER_SECOND*2)
412+
413+
# Write another bucketful to empty the token bucket completely.
414+
write_bucketful()
415+
416+
# The next bucketful should be written at the rate limit.
417+
self.assertAlmostEqual(
418+
write_bucketful(),MAX_KB_PER_SECOND,
419+
delta=MAX_KB_PER_SECOND*0.1
420+
)
421+
422+
# Once the token bucket refills, we should go back to full speed.
423+
sleep(BUCKET_KB/MAX_KB_PER_SECOND)
424+
self.assertGreater(write_bucketful(),MAX_KB_PER_SECOND*2)
Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Fix Android stdout and stderr messages being truncated or lost.

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp