classification
Title: test_asyncio leaked [3, 3, 3] references, sum=9
Type: Stage: resolved
Components: asyncio, Tests Versions: Python 3.9
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: aeros, asvetlov, vstinner, yselivanov
Priority: normal Keywords: patch

Created on 2020-03-30 14:38 by vstinner, last changed 2020-04-02 02:47 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 19282 merged aeros, 2020-04-01 20:40
Messages (5)
msg365318 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-03-30 14:38
x86 Gentoo Refleaks 3.x:
https://buildbot.python.org/all/#/builders/16/builds/128

test_asyncio leaked [3, 3, 3] references, sum=9
test_asyncio leaked [3, 5, 3] memory blocks, sum=11

3:26:23 load avg: 3.78 Re-running test_asyncio in verbose mode
test_asyncio leaked [3, 3, 24] references, sum=30
test_asyncio leaked [3, 3, 26] memory blocks, sum=32
msg365332 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-03-30 16:53
The leak was introduced by:

commit b61b818d916942aad1f8f3e33181801c4a1ed14b (HEAD, refs/bisect/bad)
Author: Kyle Stanley <aeros167@gmail.com>
Date:   Fri Mar 27 15:31:22 2020 -0400

    bpo-39812: Remove daemon threads in concurrent.futures (GH-19149)
    
    Remove daemon threads from :mod:`concurrent.futures` by adding
    an internal `threading._register_atexit()`, which calls registered functions
    prior to joining all non-daemon threads. This allows for compatibility
    with subinterpreters, which don't support daemon threads.

The leaking test is:

$ ./python -m test --fail-env-changed -R 3:3 test_asyncio -m test.test_asyncio.test_events.EPollEventLoopTests.test_run_in_executor_cancel
0:00:00 load avg: 0.56 Run tests sequentially
0:00:00 load avg: 0.56 [1/1] test_asyncio
beginning 6 repetitions
123456
......
test_asyncio leaked [1, 1, 1] references, sum=3
test_asyncio leaked [2, 1, 1] memory blocks, sum=4
test_asyncio failed

== Tests result: FAILURE ==

1 test failed:
    test_asyncio

Total duration: 4.2 sec
Tests result: FAILURE
msg365504 - (view) Author: Kyle Stanley (aeros) * (Python committer) Date: 2020-04-01 19:25
Currently working on addressing this, see bpo-39812. If I can't find a fix by tonight, I'll open a PR to revert it for now so that other regressions don't go undetected in the meantime.
msg365506 - (view) Author: Kyle Stanley (aeros) * (Python committer) Date: 2020-04-01 20:19
I was able to find a fix! Specifically, I think the issue was a subtle problem with test_run_in_executor_cancel: it never properly shuts down the executor prior to closing the event loop. 

We do this in asyncio.run() (with the loop.shutdown_default_executor() that I added last year), but it should be called explicitly when using loop.close() directly. Otherwise, the resources of the executor may not be cleaned up properly. I think the issue was being covered up because of the usage of daemon threads in the ThreadPoolExecutor, but revealed itself when the workers were converted to non-daemon threads since they require proper cleanup.

The change is very minimal:

```
    def test_run_in_executor_cancel(self):
        called = False

        def patched_call_soon(*args):
            nonlocal called
            called = True

        def run():
            time.sleep(0.05)

        f2 = self.loop.run_in_executor(None, run)
        f2.cancel()
+      self.loop.run_until_complete(
+          self.loop.shutdown_default_executor())
        self.loop.close()
        self.loop.call_soon = patched_call_soon
        self.loop.call_soon_threadsafe = patched_call_soon
        time.sleep(0.4)
        self.assertFalse(called)
```

Before change:
```
[aeros:~/repos/aeros-cpython]$ ./python -m test --fail-env-changed -R 3:3 test_asyncio -m test.test_asyncio.test_events.EPollEventLoopTests.test_run_in_executor_cancel
0:00:00 load avg: 0.63 Run tests sequentially
0:00:00 load avg: 0.63 [1/1] test_asyncio
beginning 6 repetitions
123456
......
test_asyncio leaked [1, 1, 1] references, sum=3
test_asyncio leaked [2, 1, 1] memory blocks, sum=4
test_asyncio failed

== Tests result: FAILURE ==

1 test failed:
    test_asyncio

Total duration: 3.2 sec
Tests result: FAILURE
```

After change:
```
[aeros:~/repos/aeros-cpython]$ ./python -m test --fail-env-changed -R 3:3 test_asyncio -m test.test_asyncio.test_events.EPollEventLoopTests.test_run_in_executor_cancel
0:00:00 load avg: 0.24 Run tests sequentially
0:00:00 load avg: 0.24 [1/1] test_asyncio
beginning 6 repetitions
123456
......

== Tests result: SUCCESS ==

1 test OK.

Total duration: 3.5 sec
Tests result: SUCCESS
```

I'll also test the PR using the `test-with-buildbots` label to double check, it should be attached to this issue within the next couple of hours.
msg365562 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2020-04-02 02:46
New changeset 8ec7cb53f0705509bac20c96d19fdbd9baec0cb2 by Kyle Stanley in branch 'master':
bpo-40115: Fix refleak in test_asyncio.test_run_in_executor_cancel() (GH-19282)
https://github.com/python/cpython/commit/8ec7cb53f0705509bac20c96d19fdbd9baec0cb2
History
Date User Action Args
2020-04-02 02:47:50vstinnersetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2020-04-02 02:46:52vstinnersetmessages: + msg365562
2020-04-01 20:40:11aerossetkeywords: + patch
stage: patch review
pull_requests: + pull_request18639
2020-04-01 20:19:49aerossetmessages: + msg365506
2020-04-01 19:25:11aerossetnosy: + aeros
messages: + msg365504
2020-03-30 16:53:46vstinnersetmessages: + msg365332
2020-03-30 14:38:30vstinnercreate