classification
Title: test_asyncio unstable in refleak mode
Type: behavior Stage: resolved
Components: asyncio, Tests Versions: Python 3.5, Python 3.4
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: giampaolo.rodola, gvanrossum, haypo, pitrou, python-dev, yselivanov, zach.ware
Priority: normal Keywords: patch

Created on 2014-07-30 00:31 by pitrou, last changed 2014-08-04 16:19 by python-dev. This issue is now closed.

Files
File name Uploaded Description Edit
issue22104.diff zach.ware, 2014-07-30 14:39 review
Messages (8)
msg224280 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-07-30 00:31
test_asyncio doesn't give usable results when looking for refleaks:

$ ./python -m test -R 2:4 test_asyncio
[1/1] test_asyncio
beginning 6 repetitions
123456
......
test_asyncio leaked [212, -106, 265, -6360] references, sum=-5989
test_asyncio leaked [59, -29, 76, -1799] memory blocks, sum=-1693
1 test failed:
    test_asyncio
msg224284 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2014-07-30 01:41
Was this always so or did it recently start?  Victor has made a ton of changes.

Anyway, I imagine there may be some objects stuck in cycles and the collection may not happen until a random later time, and the tests do timing-specific stuff so the number of objects created and deleted varies per run.

Perhaps adding some well-aimed gc.collect() calls to some tearDown() methods would make this go away?
msg224287 - (view) Author: Zachary Ware (zach.ware) * (Python committer) Date: 2014-07-30 04:04
I think I'm to blame for exposing this in 4f9f7e0fe1fd.  I have a theory on why that exposed it; I think regrtest is holding an extra reference to the TestSuite in runtest_inner since it is using a different branch now that test_asyncio doesn't have a test_main function.
msg224288 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-07-30 07:34
It may be related to the issue #17911.
msg224293 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-07-30 10:08
> It may be related to the issue #17911.

I checked: it is. The strange reference count can be seen with a single test. Example:

$ ./python -m test -R 3:3: -m test_default_exc_handler_coro test_asyncio 
[1/1] test_asyncio
beginning 6 repetitions
123456
......
test_asyncio leaked [53, 53, -106] references, sum=0
test_asyncio leaked [15, 15, -30] memory blocks, sum=0
1 test failed:
    test_asyncio

This test uses a coroutine which raises an exception. The exception is stored in a Task object. But the exception contains also a traceback which indirectly creates a reference cycle. For example, the zero_error_coro() coroutine of the test uses the free variable "self".

It's very difficult to find all objects of a reference cycle. We can try to break some cycles, it's already done Task._step() which sets self to None, but it's a waste of time. IMO the correct fix is to not store frame objects in an exception: see the issue #17911.
msg224305 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-07-30 13:27
Le 30/07/2014 06:08, STINNER Victor a écrit :
>
> This test uses a coroutine which raises an exception. The exception
> is
stored in a Task object. But the exception contains also a traceback
which indirectly creates a reference cycle.

regrtest calls gc.collect().
msg224311 - (view) Author: Zachary Ware (zach.ware) * (Python committer) Date: 2014-07-30 14:39
I checked on my theory, and removing the extra reference to 'tests' from the runtest_inner scope fixes it for me:

$ python -m test -R 3:3: test_asyncio
Running Debug|Win32 interpreter...
[1/1] test_asyncio
beginning 6 repetitions
123456
......
1 test OK.

Here's the patch.
msg224741 - (view) Author: Roundup Robot (python-dev) Date: 2014-08-04 16:19
New changeset 9bca86812857 by Zachary Ware in branch '3.4':
Issue #22104: Don't hold a reference to the loaded TestSuite in runtest_inner
http://hg.python.org/cpython/rev/9bca86812857

New changeset 7bc53cf8b2df by Zachary Ware in branch 'default':
Closes #22104: Merge with 3.4
http://hg.python.org/cpython/rev/7bc53cf8b2df
History
Date User Action Args
2014-08-29 05:42:19zach.warelinkissue20745 superseder
2014-08-04 16:19:11python-devsetstatus: open -> closed

nosy: + python-dev
messages: + msg224741

resolution: fixed
stage: needs patch -> resolved
2014-07-30 14:39:47zach.waresetfiles: + issue22104.diff
keywords: + patch
messages: + msg224311
2014-07-30 13:27:46pitrousetmessages: + msg224305
2014-07-30 10:08:04hayposetmessages: + msg224293
2014-07-30 10:03:40hayposetcomponents: + asyncio
2014-07-30 07:34:35hayposetmessages: + msg224288
2014-07-30 04:04:47zach.waresetnosy: + zach.ware
messages: + msg224287
2014-07-30 01:41:49gvanrossumsetmessages: + msg224284
2014-07-30 00:31:21pitroucreate