Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test_asyncio: test_sock_sendfile_mix_with_regular_send() hangs on FreeBSD #77534

Closed
vstinner opened this issue Apr 25, 2018 · 20 comments
Closed

test_asyncio: test_sock_sendfile_mix_with_regular_send() hangs on FreeBSD #77534

vstinner opened this issue Apr 25, 2018 · 20 comments
Labels
3.7 (EOL) end of life 3.8 only security fixes topic-asyncio

Comments

@vstinner
Copy link
Member

BPO 33353
Nosy @vstinner, @asvetlov, @1st1, @koobs, @miss-islington
PRs
  • bpo-33353: test_asyncio uses smaller sendfile data #7083
  • [3.7] bpo-33353: test_asyncio uses smaller sendfile data (GH-7083) #7084
  • bpo-33353: test_asyncio set SO_SNDBUF after connect #7086
  • [3.7] bpo-33353: Fix test_asyncio on FreeBSD #7087
  • bpo-33353: test_asyncio use set_write_buffer_limits() #7200
  • [3.7] bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200) #7202
    		•

    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']
    @vstinner
    Copy link
    Member Author

    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 vstinner added 3.7 (EOL) end of life 3.8 only security fixes topic-asyncio labels Apr 25, 2018
    @vstinner
    Copy link
    Member Author

    New changeset 2932755 by Victor Stinner in branch 'master':
    bpo-33353: test_asyncio uses smaller sendfile data (bpo-7083)
    2932755

    @vstinner
    Copy link
    Member Author

    My change caused a regression on macOS: bpo-33626. I just closed this issue as a duplicate of this one.

    @vstinner
    Copy link
    Member Author

    New changeset b97de3d by Victor Stinner in branch 'master':
    bpo-33353: test_asyncio set SO_SNDBUF after connect (GH-7086)
    b97de3d

    @vstinner
    Copy link
    Member Author

    New changeset fa24c1c by Victor Stinner in branch '3.7':
    [3.7] bpo-33353: Fix test_asyncio on FreeBSD (GH-7087)
    fa24c1c

    @vstinner
    Copy link
    Member Author

    bpo-32708 has been marked as a duplicate of this issue.

    @vstinner
    Copy link
    Member Author

    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
    Copy link
    Member Author

    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

    @vstinner vstinner reopened this May 28, 2018
    @1st1
    Copy link
    Member

    1st1 commented May 28, 2018

    Andrew, I'm out of capacity here, could you please take a look when you have time?

    @vstinner
    Copy link
    Member Author

    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
    Copy link
    Member Author

    http://buildbot.python.org/all/#/builders/112/builds/62

    On the previous build, test_asyncio only took 3 min 54 sec: far from the 15 min timeout limit :-(

    @vstinner
    Copy link
    Member Author

    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:

    • master (commit 73cbe7a): 22 min 28 sec (!!!)
    • PR 7200 with BUF_SIZE = 1 KiB: 47 sec
    • PR 7200 with BUF_SIZE = 4 KiB: 12 sec

    @vstinner
    Copy link
    Member Author

    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
    Copy link
    Member Author

    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
    Copy link
    Member Author

    New changeset 9551f77 by Victor Stinner in branch 'master':
    bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
    9551f77

    @vstinner
    Copy link
    Member Author

    "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
    Copy link
    Contributor

    New changeset 441afbd by Miss Islington (bot) in branch '3.7':
    bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
    441afbd

    @1st1
    Copy link
    Member

    1st1 commented May 29, 2018

    It seems like Yury's commit 7165754 made sendfile tests of test_asyncio 6x slower on FreeBSD :-(

    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
    Copy link
    Member Author

    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
    Copy link
    Member Author

    Tests are maybe not perfect, but the initial issue is fixed: test_asyncio pass again on FreeBSD buildbots.

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Assignees
    No one assigned
    Labels
    3.7 (EOL) end of life 3.8 only security fixes topic-asyncio
    Projects
    None yet
    Milestone
    No milestone
    Development

    No branches or pull requests
    3 participants
    @vstinner @1st1 @miss-islington