Issue 25272: asyncio tests are getting noisy (original) (raw)

Created on 2015-09-29 18:59 by gvanrossum, last changed 2022-04-11 14:58 by admin. This issue is now closed.

Messages (6)
msg251875 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2015-09-29 18:59
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=> .........................................................................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)
msg251984 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2015-10-01 00:40
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..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
msg251997 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2015-10-01 06:39
> Executing <Task finished coro=<CoroutineTests.test_async_def_wrapped..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.
msg252043 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2015-10-01 18:05
Or call gc.collect() in that TestCase.setUp()?
msg255490 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2015-11-27 21:38
New messages seen in Issue 25693 and Issue 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)
msg256620 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2015-12-17 23:01
I think I've fixed all of these: https://github.com/python/asyncio/commit/cd4fdbb9ccd7c41a4e7c6b416bb2481ab0e21e1c https://github.com/python/asyncio/commit/1365ac3a37836c6ec50138df8d64a87cdd0ac494 https://github.com/python/asyncio/commit/ae30b2b4244f1526d422500a1313c0c3dfd72dfe https://github.com/python/asyncio/commit/5672730e26c555485447694e576c98d2a49341b9 I also updated asyncio/runtests.py to print out all warnings: https://github.com/python/asyncio/commit/f25127c24aa8ca94960b5c012eb72afcef14403a Closing this issue.
History
Date User Action Args
2022-04-11 14:58:21 admin set github: 69459
2015-12-17 23:01:38 yselivanov set status: open -> closedresolution: fixedmessages: +
2015-12-05 12:24:32 SilentGhost link issue25806 superseder
2015-11-27 21:38:23 martin.panter set messages: + versions: + Python 3.4
2015-11-27 21:34:59 martin.panter link issue25748 superseder
2015-11-22 09:11:25 martin.panter link issue25693 superseder
2015-10-01 18:05:32 gvanrossum set messages: +
2015-10-01 06:39:15 vstinner set messages: +
2015-10-01 00:40:54 martin.panter set nosy: + martin.pantermessages: +
2015-09-29 18:59:11 gvanrossum create