msg315733 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-04-25 14:08 |
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 a19fb3c6aaa7632410d1d9dcb395d7101d124da4, bpo-32622.
The FreeBSD 3.7 and 3.x buildbots are broken, likely since this commit.
|
msg317470 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-23 22:56 |
New changeset 2932755cc11fd82b4908d60b24b837aa4f3028e6 by Victor Stinner in branch 'master':
bpo-33353: test_asyncio uses smaller sendfile data (#7083)
https://github.com/python/cpython/commit/2932755cc11fd82b4908d60b24b837aa4f3028e6
|
msg317481 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-24 00:31 |
My change caused a regression on macOS: bpo-33626. I just closed this issue as a duplicate of this one.
|
msg317483 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-24 00:43 |
New changeset b97de3dd86046ac46567146d86a69d4f78ea09db by Victor Stinner in branch 'master':
bpo-33353: test_asyncio set SO_SNDBUF after connect (GH-7086)
https://github.com/python/cpython/commit/b97de3dd86046ac46567146d86a69d4f78ea09db
|
msg317489 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-24 01:21 |
New changeset fa24c1c5afa9ba2453d88db5ed6b9d2cc3b58384 by Victor Stinner in branch '3.7':
[3.7] bpo-33353: Fix test_asyncio on FreeBSD (GH-7087)
https://github.com/python/cpython/commit/fa24c1c5afa9ba2453d88db5ed6b9d2cc3b58384
|
msg317496 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-24 01:35 |
bpo-32708 has been marked as a duplicate of this issue.
|
msg317503 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-24 02:04 |
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.
|
msg317944 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-28 22:56 |
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
|
msg317946 - (view) |
Author: Yury Selivanov (yselivanov) * |
Date: 2018-05-28 23:00 |
Andrew, I'm out of capacity here, could you please take a look when you have time?
|
msg317953 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-28 23:14 |
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
|
msg317955 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-28 23:18 |
> 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 :-(
|
msg318022 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 13:07 |
Yury Selivanov made recent changes on sendfile(): bpo-32410, commit 7165754b6b5f3b7c07050d921fa1c58bba5f0ff1.
I ran the following command on my FreeBSD VM:
./python -m test test_asyncio -m '*sendfile*' -v
Results:
* master (commit 73cbe7a01a22d02dbe1ec841e8779c775cad3d08): 22 min 28 sec (!!!)
* PR 7200 with BUF_SIZE = 1 KiB: 47 sec
* PR 7200 with BUF_SIZE = 4 KiB: 12 sec
|
msg318023 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 13:14 |
Timing at my previous commit b97de3dd86046ac46567146d86a69d4f78ea09db: 3 min 40 sec
It seems like Yury's commit 7165754b6b5f3b7c07050d921fa1c58bba5f0ff1 made sendfile tests of test_asyncio 6x slower on FreeBSD :-(
|
msg318024 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 13:22 |
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...
|
msg318029 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 14:02 |
New changeset 9551f7719213243fd96c4f284079243773c26b3c by Victor Stinner in branch 'master':
bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
https://github.com/python/cpython/commit/9551f7719213243fd96c4f284079243773c26b3c
|
msg318032 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 14:08 |
"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 9551f7719213243fd96c4f284079243773c26b3c by using a buffer of 128 KiB instead of 64 KiB.
I created the issue bpo-33683 to discuss this weird behaviour.
|
msg318036 - (view) |
Author: miss-islington (miss-islington) |
Date: 2018-05-29 14:21 |
New changeset 441afbd9c3ae3a9f1d6c985c8aa13e6205ba080b by Miss Islington (bot) in branch '3.7':
bpo-33353: test_asyncio use set_write_buffer_limits() (GH-7200)
https://github.com/python/cpython/commit/441afbd9c3ae3a9f1d6c985c8aa13e6205ba080b
|
msg318042 - (view) |
Author: Yury Selivanov (yselivanov) * |
Date: 2018-05-29 15:09 |
> It seems like Yury's commit 7165754b6b5f3b7c07050d921fa1c58bba5f0ff1 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.
|
msg318054 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 16:09 |
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.
|
msg318079 - (view) |
Author: STINNER Victor (vstinner) * |
Date: 2018-05-29 19:59 |
Tests are maybe not perfect, but the initial issue is fixed: test_asyncio pass again on FreeBSD buildbots.
|
|
Date |
User |
Action |
Args |
2022-04-11 14:58:59 | admin | set | github: 77534 |
2018-05-29 19:59:23 | vstinner | set | status: open -> closed resolution: fixed messages:
+ msg318079
stage: patch review -> resolved |
2018-05-29 16:09:00 | vstinner | set | messages:
+ msg318054 |
2018-05-29 15:09:43 | yselivanov | set | messages:
+ msg318042 |
2018-05-29 14:21:49 | miss-islington | set | nosy:
+ miss-islington messages:
+ msg318036
|
2018-05-29 14:08:13 | vstinner | set | messages:
+ msg318032 |
2018-05-29 14:02:46 | miss-islington | set | pull_requests:
+ pull_request6837 |
2018-05-29 14:02:10 | vstinner | set | messages:
+ msg318029 |
2018-05-29 13:22:15 | vstinner | set | messages:
+ msg318024 |
2018-05-29 13:14:04 | vstinner | set | messages:
+ msg318023 |
2018-05-29 13:07:00 | vstinner | set | messages:
+ msg318022 |
2018-05-29 12:31:13 | vstinner | set | stage: resolved -> patch review pull_requests:
+ pull_request6835 |
2018-05-28 23:18:20 | vstinner | set | messages:
+ msg317955 |
2018-05-28 23:14:04 | vstinner | set | messages:
+ msg317953 |
2018-05-28 23:00:23 | yselivanov | set | messages:
+ msg317946 |
2018-05-28 22:56:06 | vstinner | set | status: closed -> open resolution: fixed -> (no value) messages:
+ msg317944
|
2018-05-24 02:04:08 | vstinner | set | status: open -> closed resolution: fixed messages:
+ msg317503
stage: patch review -> resolved |
2018-05-24 01:35:13 | vstinner | set | messages:
+ msg317496 |
2018-05-24 01:35:00 | vstinner | link | issue32708 superseder |
2018-05-24 01:21:16 | vstinner | set | messages:
+ msg317489 |
2018-05-24 00:58:14 | vstinner | set | pull_requests:
+ pull_request6721 |
2018-05-24 00:43:48 | vstinner | set | messages:
+ msg317483 |
2018-05-24 00:32:27 | vstinner | link | issue33626 superseder |
2018-05-24 00:31:58 | vstinner | set | messages:
+ msg317481 |
2018-05-24 00:29:00 | vstinner | set | pull_requests:
+ pull_request6719 |
2018-05-23 22:57:25 | miss-islington | set | pull_requests:
+ pull_request6716 |
2018-05-23 22:56:11 | vstinner | set | messages:
+ msg317470 |
2018-05-23 22:38:58 | vstinner | set | keywords:
+ patch stage: patch review pull_requests:
+ pull_request6714 |
2018-04-25 14:08:30 | vstinner | create | |