test_codecs leaks references

[zware]

BPO	22166
Nosy	@malemburg, @ncoghlan, @pitrou, @vstinner, @zware, @serhiy-storchaka, @matrixise
Files	issue22166_debugging_codec_test_leak.diff: Some ideas & tracemalloc hacks issue22166_debugging_codec_test_leak_v2.diff: Display full tracebacks from tracemalloc test_codecs_fix1.patch issue22166_no_leaks_too_many_changes.diff: Removes leaks, but has unnecessary changes issue22166_clear_internal_cache.diff: Minimal fix - just clears the internal cache via gc.get_referrers() issue22166_with_forget_codec_helper_api.diff: Pop from internal cache via private _codecs._forget_codec API

^{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/serhiy-storchaka'
closed_at = <Date 2019-03-20.02:49:33.324>
created_at = <Date 2014-08-07.20:49:27.582>
labels = ['3.7', '3.8', 'type-bug', 'tests']
title = 'test_codecs leaks references'
updated_at = <Date 2019-03-20.02:49:33.323>
user = 'https://github.com/zware'

bugs.python.org fields:

activity = <Date 2019-03-20.02:49:33.323>
actor = 'vstinner'
assignee = 'serhiy.storchaka'
closed = True
closed_date = <Date 2019-03-20.02:49:33.324>
closer = 'vstinner'
components = ['Tests']
creation = <Date 2014-08-07.20:49:27.582>
creator = 'zach.ware'
dependencies = []
files = ['36362', '36363', '36524', '36559', '36560', '36563']
hgrepos = []
issue_num = 22166
keywords = ['patch']
message_count = 27.0
messages = ['225040', '225263', '225268', '225270', '226252', '226253', '226254', '226259', '226262', '226485', '226486', '226488', '226489', '226490', '226494', '226505', '226512', '226513', '226520', '226911', '226914', '226915', '245897', '331925', '331967', '338026', '338437']
nosy_count = 8.0
nosy_names = ['lemburg', 'ncoghlan', 'pitrou', 'vstinner', 'python-dev', 'zach.ware', 'serhiy.storchaka', 'matrixise']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue22166'
versions = ['Python 3.7', 'Python 3.8']

[zware]

After 9bca86812857 (bpo-22104), test_codecs now reports "leaked" references from ExceptionChainingTest. Previously the tests were only ever loaded one time, so each run of the tests was actually using the same set of TestCase instances; now the tests are freshly loaded before every test run and thus each run uses a new set of TestCase instances. My suspicion is that this is coming into play in ExceptionChainingTest.setUp, where the test's codec_name attribute is derived from the repr and id of the TestCase instance. However, I'm not familiar enough with the codecs code to know where it's going wrong from there.

One possible "fix" is to abuse load_tests to ensure the tests are only loaded once:

_suite = None

def load_tests(loader, suite, pattern):
    global _suite
    if _suite is None:
        _suite = suite
    return _suite

...which restores the old behavior, but strikes me as a fairly horrible hack. Somewhat less bad would be to just skip those tests when they've already been run before. I can't help but feel that there has to be a better solution that I can't see, though.

Nick, as the original author of the test class in question, do you have any insight into a better way to fix the "leaks"?

[ncoghlan]

I did a bit of poking around with tracemalloc (debugging patch diff attached)

encodings._cache is definitely one culprit, but something else is going on where it appears the *test cases* are being kept alive.

For comparison, with my hacked regrtest, I get this for test_cmd_line:

$ ./python -m test -R 3:1 test_grammar
[1/1] test_grammar
beginning 4 repetitions
1234
....[ Top 20 differences ]
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:37: size=9936 B (+9936 B), count=54 (+54), average=184 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:38: size=6696 B (+6696 B), count=54 (+54), average=124 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:48: size=6480 B (+6480 B), count=27 (+27), average=240 B
/home/ncoghlan/devel/py34/Lib/mimetypes.py:487: size=6176 B (+6176 B), count=1 (+1), average=6176 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:272: size=2362 B (+2362 B), count=12 (+12), average=197 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:99: size=2167 B (+2167 B), count=11 (+11), average=197 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:274: size=2137 B (+2137 B), count=11 (+11), average=194 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:92: size=1944 B (+1944 B), count=27 (+27), average=72 B
/home/ncoghlan/devel/py34/Lib/test/regrtest.py:1466: size=1568 B (+1568 B), count=1 (+1), average=1568 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:84: size=1344 B (+1344 B), count=14 (+14), average=96 B
/home/ncoghlan/devel/py34/Lib/contextlib.py:38: size=656 B (+656 B), count=1 (+1), average=656 B
/home/ncoghlan/devel/py34/Lib/unittest/suite.py:87: size=512 B (+512 B), count=1 (+1), average=512 B
/home/ncoghlan/devel/py34/Lib/test/support/__init__.py:1735: size=488 B (+488 B), count=1 (+1), average=488 B
/home/ncoghlan/devel/py34/Lib/mimetypes.py:534: size=416 B (+416 B), count=1 (+1), average=416 B
/home/ncoghlan/devel/py34/Lib/mimetypes.py:384: size=416 B (+416 B), count=1 (+1), average=416 B
/home/ncoghlan/devel/py34/Lib/test/regrtest.py:1475: size=224 B (+224 B), count=1 (+1), average=224 B
/home/ncoghlan/devel/py34/Lib/test/regrtest.py:1464: size=224 B (+224 B), count=1 (+1), average=224 B
/home/ncoghlan/devel/py34/Lib/mimetypes.py:387: size=224 B (+224 B), count=1 (+1), average=224 B
/home/ncoghlan/devel/py34/Lib/linecache.py:31: size=224 B (+224 B), count=1 (+1), average=224 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:103: size=224 B (+224 B), count=1 (+1), average=224 B

test_grammar leaked [-3] references, sum=-3
1 test failed:
test_grammar

While for test_codecs I get this:

$ ./python -m test -R 3:1 test_codecs
[1/1] test_codecs
beginning 4 repetitions
1234
....[ Top 20 differences ]
/home/ncoghlan/devel/py34/Lib/unittest/case.py:408: size=83.7 KiB (+83.7 KiB), count=206 (+206), average=416 B
/home/ncoghlan/devel/py34/Lib/unittest/case.py:368: size=41.8 KiB (+41.8 KiB), count=411 (+411), average=104 B
/home/ncoghlan/devel/py34/Lib/unittest/case.py:387: size=16.1 KiB (+16.1 KiB), count=206 (+206), average=80 B
/home/ncoghlan/devel/py34/Lib/unittest/suite.py:60: size=14.5 KiB (+14.5 KiB), count=206 (+206), average=72 B
/home/ncoghlan/devel/py34/Lib/unittest/case.py:381: size=13.6 KiB (+13.6 KiB), count=174 (+174), average=80 B
/home/ncoghlan/devel/py34/Lib/test/test_codecs.py:2653: size=12.2 KiB (+12.2 KiB), count=2 (+2), average=6242 B
/home/ncoghlan/devel/py34/Lib/test/regrtest.py:1475: size=12.0 KiB (+12.0 KiB), count=1 (+1), average=12.0 KiB
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:37: size=9936 B (+9936 B), count=54 (+54), average=184 B
/home/ncoghlan/devel/py34/Lib/unittest/loader.py:156: size=7600 B (+7600 B), count=95 (+95), average=80 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:38: size=6696 B (+6696 B), count=54 (+54), average=124 B
/home/ncoghlan/devel/py34/Lib/_weakrefset.py:48: size=6480 B (+6480 B), count=27 (+27), average=240 B
/home/ncoghlan/devel/py34/Lib/mimetypes.py:487: size=6176 B (+6176 B), count=1 (+1), average=6176 B
/home/ncoghlan/devel/py34/Lib/unittest/case.py:625: size=3232 B (+3232 B), count=4 (+4), average=808 B
/home/ncoghlan/devel/py34/Lib/test/test_codecs.py:2637: size=2964 B (+2964 B), count=6 (+6), average=494 B
/home/ncoghlan/devel/py34/Lib/test/support/__init__.py:1739: size=2432 B (+2432 B), count=32 (+32), average=76 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:272: size=2362 B (+2362 B), count=12 (+12), average=197 B
/home/ncoghlan/devel/py34/Lib/unittest/loader.py:70: size=2304 B (+2304 B), count=32 (+32), average=72 B
/home/ncoghlan/devel/py34/Lib/unittest/suite.py:125: size=2168 B (+2168 B), count=7 (+7), average=310 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:274: size=2137 B (+2137 B), count=11 (+11), average=194 B
/home/ncoghlan/devel/py34/Lib/ctypes/__init__.py:99: size=2071 B (+2071 B), count=10 (+10), average=207 B

test_codecs leaked [5602] references, sum=5602
test_codecs leaked [1056] memory blocks, sum=1056
1 test failed:
test_codecs

[ncoghlan]

Still not sure what is going on, but I tweaked my tracemalloc hacks based on Victor's draft patch in 19816 (his are designed to make this optional, where mine are hardcoded. I also sort by number of allocations, rather than amount of memory)

[ncoghlan]

I assigned this to myself when I thought this was going to be an easy fix (since I knew encodings._cache wasn't getting cleared), but it looks substantially more complicated than that.

I checked the codec entry was getting cleared by tearDown() correctly, and explicitly clearing the cycle between the test case and the codec implementation didn't help anything.

Restoring the cache to its original state did help, but only a little bit.

It may be one of the other test cases that's the problem, or else there may be something genuinely odd going on with the exception chaining and local variables.

[vstinner]

ExceptionChainingTest uses a function to raise an arbitrary exception. Problem: the function and its parameter becomes part of the exception traceback. Shortly, the exception links indirectly to itself in a nice reference cycle...

Example:
---

import traceback

class Err(Exception):
    def __del__(self):
        print("del")

def raise_exc(exc):
    raise exc

e = Err()
try:
    raise_exc(e)
except Exception as e:
    t = e.__traceback__
#traceback.clear_frames(t)
e = None
print("exit")

---

Uncommand the call the clear_frames() to see the exception deleted before the exit.

[vstinner]

Attached: Draft patch to fix some reference leaks in test_codecs.

[vstinner]

ExceptionChainingTest creates a random codec name. If you change the codec name to a fixed string like "xxx", ExceptionChainingTest.test_raise_by_type() doesn't leak anymore (when test_codecs_fix1.patch is applied), but other tests start to fail.

We should maybe enhance the codecs API to be able to unregister a codec?

[pitrou]

We should maybe enhance the codecs API to be able to unregister a codec?

That would be nice. At least as a private API in 3.4.

[ncoghlan]

Yeah, the unique name was a hack to deal with the fact I couldn't unregister anything.

As a simpler short term fix for the reference leak, perhaps it would be worth trying a call to "traceback.clear_frames(caught)" as a new final line in ExceptionChainingTest.assertWrapped?

[ncoghlan]

Ah, I think I've found a possible underlying culprit: there's a separate C level "codec_search_cache" on the interpreter object that is independent of encodings._cache.

The attached patch eliminates the reference leaks entirely (using gc.get_referrers() to get a reference to the otherwise inaccessible internal interpreter cache).

However, the patch has a bunch of changes that may not be necessary if that cache is dealt with properly, so I'm going to revert everything, and *start* with fixing the cache cleanup.