test_asyncio leaked [3, 3, 3] references, sum=9

[vstinner]

BPO	40115
Nosy	@vstinner, @asvetlov, @1st1, @aeros
PRs	bpo-40115: Fix refleak in test_asyncio #19282

^{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 2020-04-02.02:47:50.011>
created_at = <Date 2020-03-30.14:38:30.704>
labels = ['tests', '3.9', 'expert-asyncio']
title = 'test_asyncio leaked [3, 3, 3] references, sum=9'
updated_at = <Date 2020-04-02.02:47:50.011>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2020-04-02.02:47:50.011>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2020-04-02.02:47:50.011>
closer = 'vstinner'
components = ['Tests', 'asyncio']
creation = <Date 2020-03-30.14:38:30.704>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 40115
keywords = ['patch']
message_count = 5.0
messages = ['365318', '365332', '365504', '365506', '365562']
nosy_count = 4.0
nosy_names = ['vstinner', 'asvetlov', 'yselivanov', 'aeros']
pr_nums = ['19282']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue40115'
versions = ['Python 3.9']

[vstinner]

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

[vstinner]

The leak was introduced by:

commit b61b818 (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

[aeros]

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.

[aeros]

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.

[vstinner]

New changeset 8ec7cb5 by Kyle Stanley in branch 'master':
bpo-40115: Fix refleak in test_asyncio.test_run_in_executor_cancel() (GH-19282)
8ec7cb5