Movatterモバイル変換


[0]ホーム

URL:


homepage

Issue36560

This issue trackerhas been migrated toGitHub, and is currentlyread-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title:test_functools leaks randomly 1 memory block
Type:Stage:resolved
Components:TestsVersions:Python 3.8
process
Status:closedResolution:out of date
Dependencies:Superseder:
Assigned To:Nosy List: kj, levkivskyi, methane, serhiy.storchaka, vstinner
Priority:normalKeywords:patch

Created on2019-04-08 14:22 byvstinner, last changed2022-04-11 14:59 byadmin. This issue is nowclosed.

Files
File nameUploadedDescriptionEdit
test_functools.pyvstinner,2019-04-08 15:33
test_functools2.pyvstinner,2019-04-08 17:11
Pull Requests
URLStatusLinkedEdit
PR 12743closedvstinner,2019-04-09 10:55
PR 12744mergedvstinner,2019-04-09 12:01
PR 12745mergedvstinner,2019-04-09 12:42
PR 12747mergedvstinner,2019-04-09 16:01
PR 12749mergedvstinner,2019-04-09 16:31
Messages (21)
msg339643 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-08 14:22
Sometimes, each run of test_functools leaks exactly 1 memory block, even when the whole test is "re-run in verbose mode". Sometimes, it doesn't leak.https://buildbot.python.org/all/#/builders/80/builds/550test_functools leaked [1, 1, 1] memory blocks, sum=3Re-running test 'test_functools' in verbose modetest_functools leaked [1, 1, 1] memory blocks, sum=3Maybe the problem comes from Example on Linux:$ ./python -m test -F -r -j1 -R 3:3 test_functools  Using random seed 3891892Run tests in parallel using 1 child processes0:00:01 load avg: 2.38 [  1] test_functools passedbeginning 6 repetitions123456......(...)0:00:06 load avg: 2.27 [  6] test_functools passedbeginning 6 repetitions123456......0:00:07 load avg: 2.27 [  7/1] test_functools failedbeginning 6 repetitions123456......test_functools leaked [1, 2, 1] memory blocks, sum=40:00:08 load avg: 2.27 [  8/1] test_functools passedbeginning 6 repetitions123456......== Tests result: FAILURE ==7 tests OK.1 test failed:    test_functoolsTotal duration: 8 sec 333 msTests result: FAILURE
msg339651 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-08 15:33
Current bisection progress: I'm able to reproduce a failure with attached test_functools.py (211 lines) using:./python -m test -F -j5 -R 3:3 test_functools  It takes between 4 and 200 runs to reproduce the failure, I don't understand what triggers the bug.I failed to identify if the bug is more likely when the system is idle or when the system is busy. It looks purely random.
msg339662 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-08 17:11
Some progress.I'm now able to reproduce the issue with attached test_functools2.py (103 lines, a single test method):$ cp (...)test_functools2.pyLib/test/$ ./configure -C --with-pydebug CFLAGS=-O0$ make$ ./python -m test -F -j5 -R 3:3 test_functools2(...)0:00:02 load avg: 0.95 [ 19/1] test_functools failedbeginning 6 repetitions123456......test_functools leaked [1, 1, 1] memory blocks, sum=3(...)Tests result: FAILUREI disabled the C accelerator _functools.I'm now trying to disable the C accelerator of abc, but I had a small issue:bpo-36565.
msg339663 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-08 17:14
The issue comes maybe from the complex code inLib/test/libregrtest/refleak.py to handle the ABC cache:    abcs = {}    for abc in [getattr(collections.abc, a) for a in collections.abc.__all__]:        if not isabstract(abc):            continue        for obj in abc.__subclasses__() + [abc]:            abcs[obj] = _get_dump(obj)[0]...    # clear type cache    sys._clear_type_cache()    # Clear ABC registries, restoring previously saved ABC registries.    abs_classes = [getattr(collections.abc, a) for a in collections.abc.__all__]    abs_classes = filter(isabstract, abs_classes)    for abc in abs_classes:        for obj in abc.__subclasses__() + [abc]:            for ref in abcs.get(obj, set()):                if ref() is not None:                    obj.register(ref())            obj._abc_caches_clear()    clear_caches()
msg339731 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 11:20
This issue isn't a real memory leak: if I use -R 3:10 instead of -R 3:3, the test doesn't fail anymore.But the issue is still annoying since it makes Refleaks buildbot workers fail randomly :-/This issue remembers me the unstable multiprocessing tests:*bpo-33735: test_multiprocessing_spawn leaked [1, 2, 1] memory blocks on AMD64 Windows8.1 Refleaks 3.7*bpo-33984: test_multiprocessing_forkserver leaked [1, 2, 1] memory blocks on x86 Gentoo Refleaks 3.xPatch to always display memory allocations differences:diff --git a/Lib/test/libregrtest/refleak.py b/Lib/test/libregrtest/refleak.pyindexd68ea63b5b..997be819fa 100644--- a/Lib/test/libregrtest/refleak.py+++ b/Lib/test/libregrtest/refleak.py@@ -118,6 +118,8 @@ def dash_R(the_module, test, indirect_test, huntrleaks):                 print(msg, file=refrep)                 refrep.flush()             failed = True+    if not failed:+        print(alloc_deltas[nwarmup:])     return failed Truncated output with the patch:vstinner@apu$ ./python -m test -F -r -j1 -R 3:10 test_functoolsUsing random seed 4308771Run tests in parallel using 1 child processes0:00:04 load avg: 0.91 [  1] test_functools passed[0, 1, 2, 0, 0, 0, 0, 0, 0, 0]...0:00:13 load avg: 0.92 [  3] test_functools passed[2, 1, 0, 0, 0, 0, 0, 0, 0, 0]...0:00:17 load avg: 0.93 [  4] test_functools passed[0, 3, 0, 0, 0, 0, 0, 0, 0, 0]...0:00:21 load avg: 0.93 [  5] test_functools passed[0, 1, 0, 0, 2, 0, 0, 0, 0, 0]...0:00:26 load avg: 0.93 [  6] test_functools passed[0, 4, 0, 0, 0, 0, 0, 0, 0, 0]...0:00:34 load avg: 0.87 [  8] test_functools passed[0, 1, 0, 2, 0, 0, 0, 0, 0, 0]...0:01:06 load avg: 1.15 [ 15] test_functools passed[0, 1, 0, 2, 0, -1, 1, 0, 0, 0]...0:01:10 load avg: 1.46 [ 16] test_functools passed[0, 4, 0, 0, 0, 0, 0, 0, -1, 1]...The maximum sum() of these list is around 5 on 10 runs: not every run leaks a memory block. It looks more like a internal cache which is "unstable" if you look at the number of allocated memory blocks.
msg339732 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 11:22
I wrotePR 12743 to modify _abc: use weakref.WeakSet rather than using directly a set of weak references. With this PR, calling _get_dump() should clear all broken weak references. I'm not sure if it's really useful for this specific issue, since dash_R_cleanup() calls obj._abc_caches_clear() on all abstract base classes (ABC): all caches must be removed before reading the total number of allocated memory blocks (sys.getallocatedblocks()).
msg339733 -(view)Author: Serhiy Storchaka (serhiy.storchaka)*(Python committer)Date: 2019-04-09 11:28
_abc was written for optimization. Your PR makes it using slower Python code. Could you please test how much this hits the performance of abc?
msg339735 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 12:05
If I modify libregrtest with the following patch:diff --git a/Lib/test/libregrtest/refleak.py b/Lib/test/libregrtest/refleak.pyindex0bb8a0a2bf..f0225a9768 100644--- a/Lib/test/libregrtest/refleak.py+++ b/Lib/test/libregrtest/refleak.py@@ -128,7 +128,7 @@ def dash_R(ns, the_module, test_name, test_func):     failed = False     for deltas, item_name, checker in [         (rc_deltas, 'references', check_rc_deltas),-        (alloc_deltas, 'memory blocks', check_rc_deltas),+        (alloc_deltas, 'memory blocks', check_fd_deltas),         (fd_deltas, 'file descriptors', check_fd_deltas)     ]:         # ignore warmup runsAnd I add the following fileLib/test/test_noop.py:import unittestclass NoopTests(unittest.TestCase):    def test_noop(self):        passregrtest detects a "leak":$ ./python -m test -R 3:3 test_noopRun tests sequentially0:00:00 load avg: 0.55 [1/1] test_noopbeginning 6 repetitions123456......test_noop leaked [0, 1, 0] memory blocks, sum=1test_noop failed== Tests result: FAILURE ==1 test failed:    test_noopTotal duration: 113 msTests result: FAILUREThe issue comes from this look inLib/test/libregrtest/refleak.py:    for i in range(repcount):        indirect_test()        alloc_after, rc_after, fd_after = dash_R_cleanup(fs, ps, pic, zdc,                                                         abcs)        print('.', end='', file=sys.stderr, flush=True)        if i >= nwarmup:            rc_deltas[i] = get_pooled_int(rc_after - rc_before)            alloc_deltas[i] = get_pooled_int(alloc_after - alloc_before)            fd_deltas[i] = get_pooled_int(fd_after - fd_before)        alloc_before = alloc_after        rc_before = rc_after        fd_before = fd_afterBecause of "if i >= nwarmup:", get_pooled_int() isn't call during "warmup", whereas the purpose of the warmup is to warmup *everything*.Maybe get_pooled_int() allocates one frame object and keeps it alive in its "zombi frame". Maybe something else is allocated and kept alive.Anything, removing "if i >= nwarmup:" to always compute deltas fix this specific issue.AttachedPR 12744 fix this bug.
msg339738 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 12:23
New changeset5aaac94eeb44697e92b0951385cd557bc27e0f6a by Victor Stinner in branch 'master':bpo-36560: Fix reference leak hunting in regrtest (GH-12744)https://github.com/python/cpython/commit/5aaac94eeb44697e92b0951385cd557bc27e0f6a
msg339768 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 16:01
New changeset9c14061a2c2df9a9b84d0aab190a50c24a0d52f4 by Victor Stinner in branch '2.7':bpo-36560: Fix reference leak hunting in regrtest (GH-12744) (GH-12745)https://github.com/python/cpython/commit/9c14061a2c2df9a9b84d0aab190a50c24a0d52f4
msg339772 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 16:26
New changesetbb4447897a5f141eecf42987a1191a3330c5d7ed by Victor Stinner in branch 'master':bpo-36560: regrtest: don't collect the GC twice (GH-12747)https://github.com/python/cpython/commit/bb4447897a5f141eecf42987a1191a3330c5d7ed
msg339777 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 16:43
> _abc was written for optimization. Your PR makes it using slower Python code. Could you please test how much this hits the performance of abc?I mostly wrotePR 12743 to debug this issue. Please see the discussion directly on the PR ;-)
msg339781 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-09 16:56
New changeset86f0354fcb815312295b923c55e39364d85d0388 by Victor Stinner in branch '3.7':[3.7]bpo-36560: regrtest: don't collect the GC twice (GH-12747) (GH-12749)https://github.com/python/cpython/commit/86f0354fcb815312295b923c55e39364d85d0388
msg339965 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-11 11:21
Patch making check on memory block leaks stricter:diff --git a/Lib/test/libregrtest/refleak.py b/Lib/test/libregrtest/refleak.pyindex235d6bfd3a..dfadabdef6 100644--- a/Lib/test/libregrtest/refleak.py+++ b/Lib/test/libregrtest/refleak.py@@ -130,7 +130,7 @@ def dash_R(ns, the_module, test_name, test_func):     failed = False     for deltas, item_name, checker in [         (rc_deltas, 'references', check_rc_deltas),-        (alloc_deltas, 'memory blocks', check_rc_deltas),+        (alloc_deltas, 'memory blocks', check_fd_deltas),         (fd_deltas, 'file descriptors', check_fd_deltas)     ]:         # ignore warmup runsUsing this patch, at least the following tests fail:* test_asyncio* test_code* test_collections* test_contextlib* test_contextlib_async* test_ctypes* test_functools* test_multiprocessing_forkserver* test_multiprocessing_spawn* test_regrtest* test_statistics* test_typing* test_xml_etree_cI didn't analyze why yet. I guess that they are not real memory leaks, but more minor issue in the code checking for memory leaks. Sadly, it seems like such small glitch can cause a whole Refleak buildbot worker to fail :-(
msg340386 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-04-17 10:16
Another example:AMD64 Fedora Rawhide Refleaks 3.6https://buildbot.python.org/all/#/builders/193/builds/5test_contextlib leaked [8, 1, 1] memory blocks, sum=10I cannot reproduce the issue on my ("idle") laptop. It sounds like a random failure (race condition).
msg353071 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2019-09-24 10:45
Recent fail on AMD64 Fedora Rawhide Refleaks 3.x:https://buildbot.python.org/all/#builders/189/builds/162test_functools leaked [1, 2, 1] memory blocks, sum=4
msg371286 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2020-06-11 14:23
AMD64 Fedora Rawhide Refleaks 3.8:https://buildbot.python.org/all/#/builders/79/builds/196test_functools leaked [1, 1, 1] memory blocks, sum=3
msg394485 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2021-05-26 22:40
I didn't see this failure recently. I close the issue.
msg400739 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2021-08-31 14:53
Recent failure on AMD64 Fedora Rawhide Refleaks 3.x:https://buildbot.python.org/all/#/builders/565/builds/131test_typing leaked [1, 1, 1] memory blocks, sum=3(...)0:46:40 load avg: 0.00 Re-running test_typing in verbose modetest_typing leaked [1, 1, 1] memory blocks, sum=3I don't reopen the issue since I failed to reproduce it.
msg400742 -(view)Author: STINNER Victor (vstinner)*(Python committer)Date: 2021-08-31 15:05
I can see the test_typing issue with this patch:diff --git a/Lib/test/libregrtest/refleak.py b/Lib/test/libregrtest/refleak.pyindexb94826a5da..49e5f03414 100644--- a/Lib/test/libregrtest/refleak.py+++ b/Lib/test/libregrtest/refleak.py@@ -124,7 +124,7 @@ def check_rc_deltas(deltas):         #         #   [5, 5, 6]         #   [10, 1, 1]-        return all(delta >= 1 for delta in deltas)+        return any(delta >= 1 for delta in deltas)      def check_fd_deltas(deltas):         return any(deltas)Examples:$ ./python -m test test_typing -R 3:20(...)beginning 23 repetitions12345678901234567890123.......................test_typing leaked [1, 1, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] memory blocks, sum=3test_typing failed (reference leak)$ ./python -m test test_typing -R 1:20WARNING: Running tests with --huntrleaks/-R and less than 3 warmup repetitions can give false positives!(...)beginning 21 repetitions123456789012345678901.....................test_typing leaked [6, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] references, sum=6test_typing leaked [4, 0, 1, 1, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] memory blocks, sum=7test_typing failed (reference leak)(...)
msg400754 -(view)Author: Ken Jin (kj)*(Python committer)Date: 2021-08-31 16:05
@Victor, with your patch applied, for test_typing (locally, Windows x64):$ ./python -m test test_typing -R 3:20Different result on every run (race condition maybe?)$ ./python -m test test_typing -R 1:20Same result as yours on every run.
History
DateUserActionArgs
2022-04-11 14:59:13adminsetgithub: 80741
2021-08-31 16:05:56kjsetnosy: +kj
messages: +msg400754
2021-08-31 15:05:41vstinnersetmessages: +msg400742
2021-08-31 14:53:03vstinnersetmessages: +msg400739
2021-05-26 22:40:21vstinnersetstatus: open -> closed
resolution: out of date
messages: +msg394485

stage: patch review -> resolved
2020-06-11 14:23:37vstinnersetmessages: +msg371286
2019-09-24 10:45:21vstinnersetmessages: +msg353071
2019-04-17 10:16:39vstinnersetmessages: +msg340386
2019-04-11 11:21:06vstinnersetmessages: +msg339965
2019-04-09 16:56:07vstinnersetmessages: +msg339781
2019-04-09 16:43:06vstinnersetmessages: +msg339777
2019-04-09 16:31:39vstinnersetpull_requests: +pull_request12676
2019-04-09 16:26:21vstinnersetmessages: +msg339772
2019-04-09 16:01:27vstinnersetpull_requests: +pull_request12674
2019-04-09 16:01:19vstinnersetmessages: +msg339768
2019-04-09 12:42:33vstinnersetpull_requests: +pull_request12668
2019-04-09 12:23:51vstinnersetmessages: +msg339738
2019-04-09 12:05:09vstinnersetmessages: +msg339735
2019-04-09 12:01:30vstinnersetpull_requests: +pull_request12667
2019-04-09 11:28:48serhiy.storchakasetnosy: +methane,levkivskyi
messages: +msg339733
2019-04-09 11:22:53vstinnersetmessages: +msg339732
2019-04-09 11:20:13vstinnersetmessages: +msg339731
2019-04-09 10:55:15vstinnersetkeywords: +patch
stage: patch review
pull_requests: +pull_request12666
2019-04-08 17:23:43serhiy.storchakasetnosy: +serhiy.storchaka
2019-04-08 17:14:54vstinnersetmessages: +msg339663
2019-04-08 17:11:59vstinnersetfiles: +test_functools2.py

messages: +msg339662
2019-04-08 15:33:24vstinnersetfiles: +test_functools.py

messages: +msg339651
2019-04-08 14:22:16vstinnercreate
Supported byThe Python Software Foundation,
Powered byRoundup
Copyright © 1990-2022,Python Software Foundation
Legal Statements

[8]ページ先頭

©2009-2026 Movatter.jp