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

asyncio tests are getting noisy #69459

Closed
gvanrossum opened this issue Sep 29, 2015 · 6 comments
Closed

asyncio tests are getting noisy #69459

gvanrossum opened this issue Sep 29, 2015 · 6 comments
Labels
performance Performance or resource usage topic-asyncio

Comments

@gvanrossum
Copy link
Member

BPO 25272
Nosy @gvanrossum, @vstinner, @vadmium, @1st1

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 2015-12-17.23:01:38.016>
created_at = <Date 2015-09-29.18:59:11.327>
labels = ['expert-asyncio', 'performance']
title = 'asyncio tests are getting noisy'
updated_at = <Date 2015-12-17.23:01:38.015>
user = 'https://github.com/gvanrossum'

bugs.python.org fields:

activity = <Date 2015-12-17.23:01:38.015>
actor = 'yselivanov'
assignee = 'none'
closed = True
closed_date = <Date 2015-12-17.23:01:38.016>
closer = 'yselivanov'
components = ['asyncio']
creation = <Date 2015-09-29.18:59:11.327>
creator = 'gvanrossum'
dependencies = []
files = []
hgrepos = []
issue_num = 25272
keywords = []
message_count = 6.0
messages = ['251875', '251984', '251997', '252043', '255490', '256620']
nosy_count = 4.0
nosy_names = ['gvanrossum', 'vstinner', 'martin.panter', 'yselivanov']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = None
status = 'closed'
superseder = None
type = 'resource usage'
url = 'https://bugs.python.org/issue25272'
versions = ['Python 3.4', 'Python 3.5', 'Python 3.6']

@gvanrossum
Copy link
Member Author

In 3.5 and up the asyncio test are pretty chatty with warnings. E.g. a recent run gave me this in 3.5:

./python.exe -m test.test_asyncio
.........................................................................................................../Users/guido/src/cpython/Lib/asyncio/selector_events.py:574: ResourceWarning: unclosed transport <_SelectorSslTransport closing fd=27>
warnings.warn("unclosed transport %r" % self, ResourceWarning)
Task was destroyed but it is pending!
task: <Task pending coro=<BaseSelectorEventLoop._accept_connection2() done, defined at /Users/guido/src/cpython/Lib/asyncio/selector_events.py:192> wait_for=<Future pending cb=[Task._wakeup()]>>
.........................................................................Task was destroyed but it is pending!
task: <Task pending coro=<BaseSelectorEventLoop._accept_connection2() running at /Users/guido/src/cpython/Lib/asyncio/selector_events.py:227> wait_for=<Future finished exception=RuntimeError('Event loop is closed',)>>
/Users/guido/src/cpython/Lib/asyncio/selector_events.py:574: ResourceWarning: unclosed transport <_SelectorSocketTransport closing fd=26>
warnings.warn("unclosed transport %r" % self, ResourceWarning)
...............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................returning true from eof_received() has no effect when using ssl
...returning true from eof_received() has no effect when using ssl
...................................................................................................................................................................................................................................................................ss
----------------------------------------------------------------------
Ran 939 tests in 25.032s

OK (skipped=2)

@gvanrossum gvanrossum added topic-asyncio performance Performance or resource usage labels Sep 29, 2015
@vadmium
Copy link
Member

vadmium commented Oct 1, 2015

Another source of noise is this warning about a task being slow to respond. I briefly investigated this a while back. I concluded that it only happens when other tests are run before it; it does not happen when test_asyncio is run alone. It is caused by the garbage collector, because I was able to stop it by invoking gc.collect() at a particular point in the test.

$ make -s -j2 && LC_TIME= ./python -bWall -m test -j0
[. . .]
[ 36/399] test_bytes
[ 37/399] test_bz2 -- running: test_buffer (32 sec), test_asyncore (42 sec), test_asyncio (44 sec)
[ 38/399] test_buffer (33 sec) -- running: test_asyncore (43 sec), test_asyncio (45 sec)
[ 39/399] test_asyncio (44 sec) -- running: test_asyncore (43 sec)
Executing <Task finished coro=<CoroutineTests.test_async_def_wrapped.<locals>.start() done, defined at /media/disk/home/proj/python/cpython/Lib/test/test_asyncio/test_pep492.py:146> result=None created at /media/disk/home/proj/python/cpython/Lib/asyncio/base_events.py:323> took 0.177 seconds
returning true from eof_received() has no effect when using ssl
returning true from eof_received() has no effect when using ssl

@vstinner
Copy link
Member

vstinner commented Oct 1, 2015

Executing <Task finished coro=<CoroutineTests.test_async_def_wrapped.<locals>.start() done, defined at /media/disk/home/proj/python/cpython/Lib/test/test_asyncio/test_pep492.py:146> result=None created at /media/disk/home/proj/python/cpython/Lib/asyncio/base_events.py:323> took 0.177 seconds

This one is trivial to fix: set loop.slow_callback_duration to 1.0
(second) or more in TestCase.set_event_loop() of asyncio.test_utils.

@gvanrossum
Copy link
Member Author

Or call gc.collect() in that TestCase.setUp()?

@vadmium
Copy link
Member

vadmium commented Nov 27, 2015

New messages seen in bpo-25693 and bpo-25748:

/tmp/cpython/Lib/threading.py:864: ResourceWarning: unclosed <socket.socket fd=24, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 58231)>
self._target(*self._args, **self._kwargs)
. . .
/tmp/cpython/Lib/asyncio/base_events.py:379: ResourceWarning: unclosed event loop <_UnixSelectorEventLoop running=False closed=False debug=False>
warnings.warn("unclosed event loop %r" % self, ResourceWarning)

@1st1
Copy link
Member

1st1 commented Dec 17, 2015

I think I've fixed all of these:

python/asyncio@cd4fdbb
python/asyncio@1365ac3
python/asyncio@ae30b2b
python/asyncio@5672730

I also updated asyncio/runtests.py to print out all warnings:

python/asyncio@f25127c

Closing this issue.

@1st1 1st1 closed this as completed Dec 17, 2015
@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
Labels
performance Performance or resource usage topic-asyncio
Projects
None yet
Development

No branches or pull requests

4 participants