Repository navigation
test_asyncio: test_sock_sendfile_mix_with_regular_send() hangs on FreeBSD #77534
Description
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 = None
closed_at = <Date 2018-05-29.19:59:23.991>
created_at = <Date 2018-04-25.14:08:30.403>
labels = ['3.7', '3.8', 'expert-asyncio']
title = 'test_asyncio: test_sock_sendfile_mix_with_regular_send() hangs on FreeBSD'
updated_at = <Date 2018-05-29.19:59:23.990>
user = 'https://github.com/vstinner'bugs.python.org fields:
activity = <Date 2018-05-29.19:59:23.990>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2018-05-29.19:59:23.991>
closer = 'vstinner'
components = ['asyncio', 'FreeBSD']
creation = <Date 2018-04-25.14:08:30.403>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 33353
keywords = ['patch']
message_count = 20.0
messages = ['315733', '317470', '317481', '317483', '317489', '317496', '317503', '317944', '317946', '317953', '317955', '318022', '318023', '318024', '318029', '318032', '318036', '318042', '318054', '318079']
nosy_count = 5.0
nosy_names = ['vstinner', 'asvetlov', 'yselivanov', 'koobs', 'miss-islington']
pr_nums = ['7083', '7084', '7086', '7087', '7200', '7202']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue33353'
versions = ['Python 3.7', 'Python 3.8']
Activity
vstinner commentedon Apr 25, 2018
Example with a timeout of 10 seconds:
vstinner@freebsd$ ./python -m test -v test_asyncio -m test_sock_sendfile_mix_with_regular_send -v --timeout=10
== CPython 3.8.0a0 (heads/master:0977091dca, Apr 25 2018, 14:02:04) [Clang 4.0.0 (tags/RELEASE_400/final 297347)]
== FreeBSD-11.1-RELEASE-amd64-64bit-ELF little-endian
== cwd: /usr/home/vstinner/prog/python/master/build/test_python_8317
== CPU count: 2
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 load avg: 0.59 [1/1] test_asyncio
test_sock_sendfile_mix_with_regular_send (test.test_asyncio.test_events.KqueueEventLoopTests) ... Timeout (0:00:10)!
Thread 0x0000000801a16000 (most recent call first):
File "/usr/home/vstinner/prog/python/master/Lib/asyncio/selector_events.py", line 456 in _sock_sendall
File "/usr/home/vstinner/prog/python/master/Lib/asyncio/events.py", line 88 in _run
File "/usr/home/vstinner/prog/python/master/Lib/asyncio/base_events.py", line 1738 in _run_once
File "/usr/home/vstinner/prog/python/master/Lib/asyncio/base_events.py", line 521 in run_forever
File "/usr/home/vstinner/prog/python/master/Lib/asyncio/base_events.py", line 553 in run_until_complete
File "/usr/home/vstinner/prog/python/master/Lib/test/test_asyncio/test_events.py", line 2117 in run_loop
File "/usr/home/vstinner/prog/python/master/Lib/test/test_asyncio/test_events.py", line 2213 in test_sock_sendfile_mix_with_regular_send
(...)
The test has been introduced in by the commit a19fb3c, bpo-32622.
The FreeBSD 3.7 and 3.x buildbots are broken, likely since this commit.
vstinner commentedon May 23, 2018
New changeset 2932755 by Victor Stinner in branch 'master':
bpo-33353: test_asyncio uses smaller sendfile data (bpo-7083)
2932755
vstinner commentedon May 24, 2018
My change caused a regression on macOS: bpo-33626. I just closed this issue as a duplicate of this one.
vstinner commentedon May 24, 2018
New changeset b97de3d by Victor Stinner in branch 'master':
bpo-33353: test_asyncio set SO_SNDBUF after connect (GH-7086)
b97de3d
vstinner commentedon May 24, 2018
New changeset fa24c1c by Victor Stinner in branch '3.7':
[3.7] bpo-33353: Fix test_asyncio on FreeBSD (GH-7087)
fa24c1c
vstinner commentedon May 24, 2018
bpo-32708 has been marked as a duplicate of this issue.
vstinner commentedon May 24, 2018
test_asyncio doesn't hang on FreeBSD 3.x buildbot anymore! macOS buildbot is back to green as well. It seems like I can close the issue.
vstinner commentedon May 28, 2018
Hum, the test still fails on AMD64 FreeBSD CURRENT Debug 3.x :-(
http://buildbot.python.org/all/#/builders/60/builds/77
test_sock_client_ops (test.test_asyncio.test_events.PollEventLoopTests) ... ok
Timeout (0:15:00)!
Thread 0x000000080139d000 (most recent call first):
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/selectors.py", line 415 in select
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/asyncio/base_events.py", line 1707 in _run_once
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/asyncio/base_events.py", line 523 in run_forever
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/asyncio/base_events.py", line 555 in run_until_complete
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/test/test_asyncio/test_events.py", line 2117 in run_loop
File "/usr/home/buildbot/python/3.x.koobs-freebsd-current/build/Lib/test/test_asyncio/test_events.py", line 2220 in test_sock_sendfile_mix_with_regular_send
1st1 commentedon May 28, 2018
Andrew, I'm out of capacity here, could you please take a look when you have time?
vstinner commentedon May 28, 2018
Similar failure on AMD64 FreeBSD CURRENT Non-Debug 3.7:
http://buildbot.python.org/all/#/builders/112/builds/62
Timeout (0:15:00)!
Thread 0x0000000801324000 (most recent call first):
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/selectors.py", line 323 in select
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/asyncio/base_events.py", line 1707 in _run_once
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/asyncio/base_events.py", line 523 in run_forever
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/asyncio/base_events.py", line 555 in run_until_complete
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/test/test_asyncio/test_events.py", line 2117 in run_loop
File "/usr/home/buildbot/python/3.7.koobs-freebsd-current.nondebug/build/Lib/test/test_asyncio/test_events.py", line 2311 in test_sendfile
vstinner commentedon May 28, 2018
On the previous build, test_asyncio only took 3 min 54 sec: far from the 15 min timeout limit :-(
vstinner commentedon May 29, 2018
Yury Selivanov made recent changes on sendfile(): bpo-32410, commit 7165754.
I ran the following command on my FreeBSD VM:
./python -m test test_asyncio -m '*sendfile*' -v
Results:
vstinner commentedon May 29, 2018
Timing at my previous commit b97de3d: 3 min 40 sec
It seems like Yury's commit 7165754 made sendfile tests of test_asyncio 6x slower on FreeBSD :-(
vstinner commentedon May 29, 2018
On my PR 7200, test_sendfile_close_peer_in_the_middle_of_receiving() fails on Windows (AppVeyor) :-(
For the SelectorEventLoop, it seems like sock.setsockopt(socket.SOL_SOCKET, socket.SO_SNDBUF, 1024) doesn't work as intented: sock.send(<16384 bytes>) returns 16384, as the 1024 limit is not taken in account :-(
Same issue for the ProactorEventLoop...
vstinner commentedon May 29, 2018
New changeset 9551f77 by Victor Stinner in branch 'master':
bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
9551f77
vstinner commentedon May 29, 2018
"On my PR 7200, test_sendfile_close_peer_in_the_middle_of_receiving() fails on Windows (AppVeyor) (...)"
I worked around this bug in my commit 9551f77 by using a buffer of 128 KiB instead of 64 KiB.
I created the issue bpo-33683 to discuss this weird behaviour.
miss-islington commentedon May 29, 2018
New changeset 441afbd by Miss Islington (bot) in branch '3.7':
bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
441afbd
1st1 commentedon May 29, 2018
Well, yeah, I kind of expected to see a performance regression here. Before, we were reading from a file directly, which is a blocking operation and can potentially block the event loop. Now we're using a thread pool to do the read, but its more overhead.
In this case I think we have to do it the *correct* way, even if it means sacrificing the performance. As a workaround, I propose to rise the read buffer size to 1Mb.
vstinner commentedon May 29, 2018
With my latest change, all sendfile tests pass in 17 sec on my FreeBSD VM, so I think that it's fine. Let's see if this test now always pass on FreeBSD buildbots.
vstinner commentedon May 29, 2018
Tests are maybe not perfect, but the initial issue is fixed: test_asyncio pass again on FreeBSD buildbots.