android: test_functools hangs on armv7

[xdegaye]

BPO	26939
Nosy	@rhettinger, @ncoghlan, @pitrou, @vstinner, @xdegaye, @moreati, @yan12125
PRs	[Do Not Merge] Convert Misc/NEWS so that it is managed by towncrier #552
Files	test_output.txt: gdb back trace python_tests_on_arm.txt atomic_explicit.patch build-failure.txt atomic_explicit2.patch pycond_timedwait.patch test_lru_cache_threaded-x86-printf.txt test_lru_cache_threaded-armv7-printf.txt pycond_timedwait_2.patch setswitchinterval.patch

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = 'https://github.com/xdegaye'
closed_at = <Date 2016-12-08.11:02:40.986>
created_at = <Date 2016-05-03.15:37:46.487>
labels = ['3.7', 'type-bug', 'tests', 'build']
title = 'android: test_functools hangs on armv7'
updated_at = <Date 2017-03-31.16:36:11.709>
user = 'https://github.com/xdegaye'

bugs.python.org fields:

activity = <Date 2017-03-31.16:36:11.709>
actor = 'dstufft'
assignee = 'xdegaye'
closed = True
closed_date = <Date 2016-12-08.11:02:40.986>
closer = 'xdegaye'
components = ['Tests', 'Cross-Build']
creation = <Date 2016-05-03.15:37:46.487>
creator = 'xdegaye'
dependencies = []
files = ['42701', '42750', '42753', '42755', '42756', '42874', '43191', '43192', '43193', '45249']
hgrepos = []
issue_num = 26939
keywords = ['patch']
message_count = 22.0
messages = ['264742', '264756', '264922', '264957', '264963', '264965', '264974', '264976', '264981', '264988', '264995', '265003', '265020', '265027', '265701', '265704', '265707', '265721', '267250', '267410', '279588', '282703']
nosy_count = 9.0
nosy_names = ['rhettinger', 'ncoghlan', 'pitrou', 'vstinner', 'neologix', 'xdegaye', 'python-dev', 'Alex.Willmer', 'yan12125']
pr_nums = ['552']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue26939'
versions = ['Python 3.6', 'Python 3.7']

[xdegaye]

test_functools hangs on an android emulator running an armv7 system image (but not on x86) at API level 21. The test suite hangs at

test_lru_cache_threaded (test.test_functools.TestLRUC) ...

A cause of this problem may be related to the fact that the android arm emulator runs very, very slowly.

[xdegaye]

The attached test_output.txt file is the corresponding gdb backtrace[1].

Interestingly, all the tests (issues bpo-26938, bpo-26939, bpo-26940 and bpo-26941) that hang on arm use sys.setswitchinterval() aggressively.

[1] The backtrace is interleaved with:

• Python Exception <type 'exceptions.UnicodeDecodeError'> 'utf8' codec can't decode byte 0xb8 in posit ion 0: invalid start byte:
  that seem to come from libpython, the python that is embeded in gdb to pretty-print gdb output
• ---Type <return> to continue, or q <return> to quit---
  sorry, had to resort to copy/paste, gdb 'set logging' does not seem to work

[pitrou]

Can you post the backtraces of all threads (at least the innermost frames)?
Also, can you reproduce on an actual armv7 machine? Just wondering if there may be something peculiar in the emulator.

[yan12125]

FWIW, test_functools passes on ASUS Zenfone 2 Laser ZE500KL with stock ROM (rooted) and my patchset. [1] The CPU is ARM64 and the Python is built as 32-bit ARM binaries. test_threading (bpo-26941) and test_importlib (bpo-26940) pass, too. test_concurrent_futures (bpo-26938) fails with 27 errors, all with "OSError: [Errno 38] Function not implemented", which seems the same as bpo-26924.

The attached file contains logs of the four tests mentioned here.

[1] https://github.com/yan12125/python3-android

[pitrou]

I suspect this bug is caused by memory ordering differences between x86 and ARM (see https://en.wikipedia.org/wiki/Memory_ordering#Runtime_memory_ordering ), which is why it may not reproduce easily (may depend on the particular CPU implementation and/or various timing subtleties in the tests themselves).

Xavier / Chi, can you tell if Android has stdatomic.h? See Include/pyatomic.h for the difference it makes.

[pitrou]

Xavier, as a strating point, can you try the following patch? (atomic_explicit.patch)
If it solves the issue, can you also measure the performance drop compared to unpatched (on a non-debug build)? python -m test.pystone should be sufficient.

[xdegaye]

Android has stdatomic.h and HAVE_STD_ATOMIC is defined.

The build fails with the patch, see the errors in the attached file. This is the native compilation of python, the patches in my build system are also applied to the native build so that they can be checked. I can prevent that if needed.

[pitrou]

Oops, sorry, hadn't seen the patch didn't compile. Can you tried with this new patch? (atomic_explicit2.patch)

[xdegaye]

Still hangs at test_lru_cache_threaded with this last patch :(

[xdegaye]

Can you post the backtraces of all threads (at least the innermost frames)?

There are two threads, gdb does not print the backtrace of the other thread. My current gdb setup with a connection to a gdb-server misses some stuff (access to the loader or some libraries I guess) and needs to be completed with the same setup as the one used by the ndk-gdb script (released by google for android applications).

Also, can you reproduce on an actual armv7 machine? Just wondering if there may be something peculiar in the emulator.

I don't have an armv7 device that can be used for testing.

[xdegaye]

The strace of test_lru_cache_threaded:

...
gettimeofday({1462553238, 580860}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 581276772}) = 0
gettimeofday({1462553238, 581672}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 582078767}) = 0
gettimeofday({1462553238, 583956}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 585865959}) = 0
gettimeofday({1462553238, 587597}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 589381724}) = 0
gettimeofday({1462553238, 589973}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 591858839}) = 0
gettimeofday({1462553238, 593003}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 593452750}) = 0
gettimeofday({1462553238, 593886}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 594364345}) = 0
gettimeofday({1462553238, 594764}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 595227771}) = 0
gettimeofday({1462553238, 595626}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 596027590}) = 0
gettimeofday({1462553238, 596448}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 596848736}) = 0
gettimeofday({1462553238, 597259}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 597665484}) = 0
gettimeofday({1462553238, 598060}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 598869963}) = 0
gettimeofday({1462553238, 599547}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1462553238, 601053152}) = 0
gettimeofday({1462553238, 601593}, NULL) = 0
clock_gettime(CLOCK_REALTIME, ^CProcess 908 detached
<detached ...>

[pitrou]

Still hangs at test_lru_cache_threaded with this last patch :(

What about the other tests (test_importlib, test_threading)?

Do you know in which precise test it hangs? (use "-v" to print test names)

There are two threads, gdb does not print the backtrace of the other thread.

Even with "thread apply all backtrace" (Google tells me this is the incantation)?