test_packaging reference leak

[pitrou]

BPO	12167
Nosy	@vsajip, @amauryfa, @pitrou, @vstinner, @benjaminp, @tarekziade, @merwok, @bitdancer, @Trundle
Files	issue12167_patch_2to3.patch packaging-caches.diff

^{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 = 'https://github.com/merwok'
closed_at = <Date 2011-10-06.11:44:28.398>
created_at = <Date 2011-05-24.10:07:25.781>
labels = ['tests', 'performance']
title = 'test_packaging reference leak'
updated_at = <Date 2011-10-06.11:44:28.398>
user = 'https://github.com/pitrou'

bugs.python.org fields:

activity = <Date 2011-10-06.11:44:28.398>
actor = 'eric.araujo'
assignee = 'eric.araujo'
closed = True
closed_date = <Date 2011-10-06.11:44:28.398>
closer = 'eric.araujo'
components = ['Tests', 'Distutils2']
creation = <Date 2011-05-24.10:07:25.781>
creator = 'pitrou'
dependencies = []
files = ['22604', '22665']
hgrepos = []
issue_num = 12167
keywords = ['patch']
message_count = 38.0
messages = ['136729', '136737', '136738', '136741', '136742', '136744', '136745', '136746', '136747', '136748', '138120', '138124', '138125', '138126', '138396', '138398', '138399', '138530', '138531', '138533', '138543', '138569', '138596', '139917', '139973', '139984', '139985', '139986', '139987', '139988', '140044', '140121', '140156', '140428', '140451', '140576', '141385', '144994']
nosy_count = 12.0
nosy_names = ['vinay.sajip', 'amaury.forgeotdarc', 'pitrou', 'vstinner', 'nadeem.vawda', 'benjamin.peterson', 'tarek', 'eric.araujo', 'r.david.murray', 'Trundle', 'alexis', 'python-dev']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'resource usage'
url = 'https://bugs.python.org/issue12167'
versions = ['Python 3.3']

[pitrou]

Looks like either packaging or test_packaging forgets to clean up after itself:

results for 9a16fa0c9548 on branch "default"
--------------------------------------------

test_packaging leaked [193, 193, 193] references, sum=579

[amauryfa]

Probably because new extension modules are built and imported on every run.

[pitrou]

Probably because new extension modules are built and imported on every run.

Well, test_distutils does the same, doesn't it?

[amauryfa]

I could not find any test in distutils/tests that imports extension modules.

[vstinner]

DistributionTestCase.test_hooks_get_run() leaks some references, I'm trying to understand where exactly.

[pitrou]

Let's see:

-> test_command_bdist_dumb.py leaks:
test_packaging leaked [7, 7] references, sum=14

-> test_dist.py leaks:
test_packaging leaked [65, 65] references, sum=130

-> test_mixin2to3.py leaks:
test_packaging leaked [60, 60] references, sum=120

-> test_pypi_dist.py leaks:
test_packaging leaked [28, 28] references, sum=56

-> test_pypi_simple.py leaks:
test_packaging leaked [12, 12] references, sum=24

-> test_uninstall.py leaks:
test_packaging leaked [5, 5] references, sum=10

-> test_util.py leaks:
test_packaging leaked [40, 40] references, sum=80

[python-dev]

New changeset 70675864717b by Victor Stinner in branch 'default':
Issue bpo-12167: packaging.tests.support, LoggingCatcher restores correctly the
http://hg.python.org/cpython/rev/70675864717b

New changeset 28c1f8480090 by Victor Stinner in branch 'default':
Issue bpo-12167: packaging.tests.test_dist unloads the temporary module
http://hg.python.org/cpython/rev/28c1f8480090

[pitrou]

In test_command_bdist, the leak is in test_simple_built().

[pitrou]

In test_mixin2to3.py, the leak is shared between the 3 test methods.

[pitrou]

In test_pypi_dist, the leak is shared between test_download() and test_unpack().

[pitrou]

Is someone investigating this?

[merwok]

I’m afraid I don’t understand enough to fix this. I looked at test_simple_built in test_command_bdist_dumb and found no C code involved.

[pitrou]

I’m afraid I don’t understand enough to fix this. I looked at
test_simple_built in test_command_bdist_dumb and found no C code
involved.

It means that either packaging or test_packaging keeps references to
more and more objects.
You don't need to know C, but you have to investigate.

[merwok]

Ah, it’s just refcounting issues? I can probably use the gc module to find them, and add del statements where appropriate to release objects.

[python-dev]

New changeset fd6446a88fe3 by Victor Stinner in branch 'default':
Issue bpo-12167: Fix a reafleak in packaging.tests.PyPIServer constructor
http://hg.python.org/cpython/rev/fd6446a88fe3

[vstinner]

test_dist and test_bdist_dumb leak because of the _path_created global variable of packaging.util, used indirectly by copy_tree().

# cache for by mkpath() -- in addition to cheapening redundant calls,
# eliminates redundant "creating /foo/bar/baz" messages in dry-run mode
_path_created = set()

I don't how/when this set should be cleared.

[vstinner]

Note: bpo-12133 has a patch to fix the ResourceWarning of test_pypi_simple.

[python-dev]

New changeset 27a70dfc38cc by Éric Araujo in branch 'default':
Packaging tests: don’t let an internal cache grow indefinitely.
http://hg.python.org/cpython/rev/27a70dfc38cc

[merwok]

I could not find any test in distutils/tests that imports extension modules.

test_build_ext builds and imports xx.

[merwok]

We’re down to 100 refleaks. Thanks to the negative refleaks of test_pydoc, we now have a few refleaks to spare! Seriously, what does a negative refleak mean?

[bitdancer]

It means that objects were garbage collected. The refleak test runs the test multiple times, and ignores the first N runs to allow the object count to "settle". But sometimes it either doesn't settle, or later runs end up with objects getting garbage collected that were created in earlier runs.

[vstinner]

test_build_ext builds and imports xx.

I changed test test to use a subprocess:

New changeset 144cea8db9a5 by Victor Stinner in branch 'default':
Issue bpo-12333: run tests on the new module in a subprocess
http://hg.python.org/cpython/rev/144cea8db9a5

It should fix refleaks because it is not possible to unload a module written in C.

[merwok]

I changed test test to use a subprocess:

Yes, in packaging. I replied to an earlier question about distutils:

>> I could not find any test in distutils/tests that imports extension modules.
> test_build_ext builds and imports xx.

[Trundle]

At least some of the remaining refleaks are caused by lib2to3. lib2to3 uses a logger with the filename as logger name (see lib2to3.fixer_base.BaseFix.set_filename()), but as the tests use a temporary file with an arbitrary name, a new logger is created on each test run iteration.

[Trundle]

Attached is a patch that replaces lib2to3.fixer_Base.BaseFix.set_filename() during tests. With the patch applied, I don't get any refleaks for packaging.

Another approach would be to simply remove the logging attribute of lib2to3 fixers, as it isn't used anyway.

[merwok]

Thanks a lot for the diagnosis.

To fix it, I don’t find the monkey-patching approach very good, I’d prefer properly using the logging API to remove handlers upon cleanup. Would you like to look into that?

[pitrou]

To fix it, I don’t find the monkey-patching approach very good, I’d
prefer properly using the logging API to remove handlers upon cleanup.

I don't think such stuff exists.

[merwok]

See http://hg.python.org/cpython/file/tip/Lib/packaging/tests/support.py#l81

[pitrou]

See http://hg.python.org/cpython/file/tip/Lib/packaging/tests/support.py#l81

AFAIU, the problem is that 2to3 creates a whole new logger for each
different file. So it's not about cleaning the handlers, but cleaning up
the loggers as well. And logging (deliberately, according to Vinay)
doesn't provide any API to destroy loggers (they are de facto eternal).

[merwok]

Thanks for clarifying, I had misread. IMO, using one logger per file is a lib2to3 bug.

[vsajip]

I can confirm what Andreas said - I just removed the two lines referencing the logger in BaseFix, and ran the regression tests - with no failures. So I, too, think those lines should go.

[merwok]

Let me clarify my position: I think there is a bug in lib2to3 that should be fixed, after what the refleak would go. (I’ll report it soon if nobody does it before.) If Benjamin rejects the bug, then I’ll agree with the monkey-patch.

[vsajip]

I've created bpo-12536 to cover the lib2to3 issue.

[merwok]

It looks like we don’t have refleaks anymore! I still have one question.

Victor reported some time ago that packaging.util._path_created was a cache that was never cleared; I fixed that in 27a70dfc38cc, but recently I’ve found that regrtest itself clears the similar distutils.util._path_created; I wonder which approach is better: one global cleaning in regrtest or piecemeal cleanup in each leaking test case?

I’ve also made a patch to register the caches used by packaging.database with the regrtest unclean environment warning; can someone review it?

[pitrou]

I’ve also made a patch to register the caches used by
packaging.database with the regrtest unclean environment warning; can
someone review it?

I would call .copy() on the original dicts rather than remembering an
explicit empty dict.

[merwok]

I would call .copy() on the original dicts rather than remembering an
explicit empty dict.

I thought about that and decided to use an empty dict as a way to add a check that the caches should start empty. Maybe it was misguided and I should instead add a unit test for that, or not bother altogether.

[merwok]

I edited my patch to use a copy instead of an explicit empty dict, but I found a bug. The restore code unpacks the saved_caches object to (cache, items), but saved_caches is (id(cache), cache, cache.copy()). I’m surprised the unpacking works; I don’t want to commit before I understand that.

[python-dev]

New changeset e76c6aaff135 by Éric Araujo in branch 'default':
Add regrtest check for caches in packaging.database (see bpo-12167)
http://hg.python.org/cpython/rev/e76c6aaff135