Modify ↓
#13356 closed defect (fixed)
Subversion pool is destroyed more than once while testing trac/versioncontrol/tests/functional.py
| Reported by: | Jun Omae | Owned by: | Jun Omae |
|---|---|---|---|
| Priority: | normal | Milestone: | 1.5.3 |
| Component: | version control | Version: | |
| Severity: | normal | Keywords: | svn114 |
| Cc: | Branch: | ||
| Release Notes: |
Fix double-destroying memory pool error from tracd server on functional-test |
||
| API Changes: | |||
| Internal Changes: | |||
Description
The trac/versioncontrol/tests/functional.py passes but AssertionError: This pool has already been destroyed is logged in testenv/testing.log.
$ make python=39 clean Trac.egg-info trac/versioncontrol/tests/functional.py
find . -name \*.py[co] -exec rm {} \;
coverage erase
rm -fr build/doc
Python: /home/jun66j5/venv/py39/bin/python
Package Version
------------------------------------------------------
Python : 3.9.2 (default, Feb 20 2021, 20:59:40)
: [GCC 5.4.0 20160609]
Setuptools : 53.1.0
Pip : 21.0.1
Wheel : not installed
Jinja2 : 2.11.3
Babel : 2.9.0
sqlite3 : 2.6.0 (3.11.0)
PySqlite : not installed
PyMySQL : 1.0.2
Psycopg2 : 2.8.6 (dt dec pq3 ext lo64)
SVN bindings : 1.14.0 (r1876290)
Mercurial : 5.7
Pygments : 2.8.0
Textile : 4.0.1
Pytz : 2021.1
Docutils : 0.16
Selenium : 3.141.0
PyTidyLib : 0.3.2
LXML : 4.6.2
coverage : 5.4
Variables:
PATH=/home/jun66j5/venv/py39/bin:/home/jun66j5/bin:/home/jun66j5/.gem/ruby/2.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin
PYTHONPATH=.
TRAC_TEST_DB_URI=
server-options= -p 3000 -a '*,/home/jun66j5/src/trac-htdigest.txt,auth' -e
External dependencies:
Git version: git version 2.29.0
Subversion version: 1.14.0
python setup.py egg_info
running egg_info
writing Trac.egg-info/PKG-INFO
writing dependency_links to Trac.egg-info/dependency_links.txt
writing entry points to Trac.egg-info/entry_points.txt
writing requirements to Trac.egg-info/requires.txt
writing top-level names to Trac.egg-info/top_level.txt
reading manifest file 'Trac.egg-info/SOURCES.txt'
writing manifest file 'Trac.egg-info/SOURCES.txt'
python -m unittest trac.versioncontrol.tests.functional.test_suite
.................
----------------------------------------------------------------------
Ran 17 tests in 25.887s
OK
127.0.0.1 - - [05/Mar/2021 21:17:37] "GET /admin/versioncontrol/repository HTTP/1.1" 200 -
127.0.0.1 - - [05/Mar/2021 21:17:38] "GET /admin/versioncontrol/repository/award_1 HTTP/1.1" 200 -
Exception ignored in: <function SubversionRepository.__del__ at 0x7efebbb88040>
Traceback (most recent call last):
File "/home/jun66j5/src/tracdev/git/tracopt/versioncontrol/svn/svn_fs.py", line 412, in __del__
self.close()
File "/home/jun66j5/src/tracdev/git/tracopt/versioncontrol/svn/svn_fs.py", line 455, in close
self.pool.destroy()
File "/home/jun66j5/src/tracdev/git/tracopt/versioncontrol/svn/svn_fs.py", line 211, in destroy
self.apr_pool_destroy(self._pool)
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/svn/core.py", line 300, in svn_pool_destroy
pool.destroy()
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/libsvn/core.py", line 9907, in destroy
self.assert_valid()
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/libsvn/core.py", line 9893, in assert_valid
assert self.valid(), "This pool has already been destroyed"
AssertionError: This pool has already been destroyed
Exception ignored in: <function Pool.__del__ at 0x7efebbb86940>
Traceback (most recent call last):
File "/home/jun66j5/src/tracdev/git/tracopt/versioncontrol/svn/svn_fs.py", line 222, in __del__
self.destroy()
File "/home/jun66j5/src/tracdev/git/tracopt/versioncontrol/svn/svn_fs.py", line 211, in destroy
self.apr_pool_destroy(self._pool)
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/svn/core.py", line 300, in svn_pool_destroy
pool.destroy()
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/libsvn/core.py", line 9907, in destroy
self.assert_valid()
File "/home/jun66j5/venv/py39/lib/python3.9/site-packages/libsvn/core.py", line 9893, in assert_valid
assert self.valid(), "This pool has already been destroyed"
AssertionError: This pool has already been destroyed
127.0.0.1 - - [05/Mar/2021 21:17:38] "GET /chrome/site/your_project_logo.png HTTP/1.1" 304 -
127.0.0.1 - - [05/Mar/2021 21:17:38] "POST /admin/versioncontrol/repository/award_1 HTTP/1.1" 303 -
Similar issue occurs on 1.4-stable with Subversion 1.14.
$ make python=27-svn114 trac/versioncontrol/tests/functional.py
Python: /home/jun66j5/venv/py27-svn114/bin/python
Package Version
-------------------------------------------------------
Python : 2.7.12 (default, Feb 25 2021, 14:00:40)
: [GCC 5.4.0 20160609]
Setuptools : 42.0.2
Pip : 19.3.1
Wheel : 0.33.6
Jinja2 : 2.11.3
Genshi : 0.7.5 (with speedups)
Babel : 2.9.0
sqlite3 : 2.6.0 (3.11.0)
PySqlite : 2.8.3 (3.31.1)
PyMySQL : 0.10.1
Psycopg2 : 2.8.6 (dt dec pq3 ext lo64)
SVN bindings : 1.14.1 (r1886195)
Mercurial : 5.7
Pygments : 2.5.2
Textile : 3.0.4
Pytz : 2021.1
Docutils : 0.16
Twill : 0.9
LXML : 4.6.2
coverage : 5.5
Variables:
PATH=/home/jun66j5/venv/py27-svn114/bin:/home/jun66j5/bin:/home/jun66j5/.gem/ruby/2.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin
PYTHONPATH=.
TRAC_TEST_DB_URI=
server-options= -p 3000 -a '*,/home/jun66j5/src/trac-htdigest.txt,auth' -e
External dependencies:
Git version: git version 2.29.0
Subversion version: 1.14.1
python -m unittest trac.versioncontrol.tests.functional.test_suite
.................
----------------------------------------------------------------------
Ran 17 tests in 14.365s
OK
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method apr_pool_t.__del__ of <libsvn.core.apr_pool_t; proxy of <Swig Object of type 'apr_pool_t *' at 0x7f52aeb14de0> >> ignored
Attachments (0)
Change History (8)
comment:1 by , 4 years ago
comment:2 by , 4 years ago
| Owner: | set to |
|---|---|
| Status: | new → assigned |
Proposed changes in [5f8aa2dff/jomae.git].
In the changes, our Pool class changes simple wrapper of svn.core.apr_pool_t object because the apr_pool_t class has the same logic of our Pool class.
$ make python=39 unit-test functional-test SKIP_FUNCTIONAL_TESTS=1 python -m unittest trac.test.test_suite ... ---------------------------------------------------------------------- Ran 2742 tests in 40.573s OK (skipped=5) python -m unittest trac.tests.functional.test_suite ... ---------------------------------------------------------------------- Ran 221 tests in 460.105s OK $ wc -l testenv/testing.log 2577 testenv/testing.log $ grep -c 'destroyed' testenv/testing.log 0
comment:3 by , 4 years ago
The changes look good. Just curious, what is the reason for wrapping core.Pool from bindings/ctypes-python/csvn/core/__init__.py rather than using core.Pool directly?
comment:4 by , 4 years ago
Trac passes the pool object to Subversion API via Pool.__call__. I thought avoiding to change calls of the method by keeping Pool.__call__ method.
- root_path_utf8 = repos.svn_repos_find_root_path(path_utf8, self.pool()) + root_path_utf8 = repos.svn_repos_find_root_path(path_utf8, self.pool)
Though, I tried to remove our Pool class, jomae.git@t13356-remove-pool-class. However, after the changes, the memory pool is not released. I'm not sure why.
Memory profiles of sync with local mirror of Genshi Subversion repository
| Trac | Subversion | Increment on repos.sync()
|
|---|---|---|
| 1.4-stable | 1.9 | 27.9 MiB |
| 1.4-stable | 1.10 | 31.0 MiB |
| 1.4-stable | 1.14 | 31.4 MiB |
| trunk | 1.14 | 21.9 MiB |
| t13356 | 1.14 | 23.8 MiB |
| t13356-remove-pool-class | 1.14 | 102.3 MiB |
memprof.py script
# -*- coding: utf-8 -*- import sys import memory_profiler import tempfile from trac.env import Environment from trac.test import rmtree from trac.versioncontrol.api import RepositoryManager @memory_profiler.profile def main(envpath, svnrepos): options = [ ('project', 'name', 'Memory profile'), ('trac', 'database', 'sqlite:db/trac.db'), ('components', 'tracopt.versioncontrol.svn', 'enabled'), ] env = Environment(envpath, create=True, options=options) env.config.set('repositories', '.type', 'svn') env.config.set('repositories', '.dir', svnrepos) env.config.save() env.shutdown() env = None env = Environment(envpath) rm = RepositoryManager(env) repos = rm.get_repository('') repos.sync() try: tmpdir = tempfile.mkdtemp(prefix='trac-') main(tmpdir, sys.argv[1]) finally: rmtree(tmpdir)
t13356-remove-pool-class with Subversion 1.14
Filename: /home/jun66j5/src/tracdev/git/memprof.py
Line # Mem usage Increment Occurences Line Contents
============================================================
11 33.9 MiB 33.9 MiB 1 @memory_profiler.profile
12 def main(envpath, svnrepos):
13 33.9 MiB 0.0 MiB 1 options = [
14 ('project', 'name', 'Memory profile'),
15 ('trac', 'database', 'sqlite:db/trac.db'),
16 ('components', 'tracopt.versioncontrol.svn', 'enabled'),
17 ]
18 50.6 MiB 16.7 MiB 1 env = Environment(envpath, create=True, options=options)
19 50.6 MiB 0.0 MiB 1 env.config.set('repositories', '.type', 'svn')
20 50.6 MiB 0.0 MiB 1 env.config.set('repositories', '.dir', svnrepos)
21 50.6 MiB 0.0 MiB 1 env.config.save()
22 50.6 MiB 0.0 MiB 1 env.shutdown()
23 50.6 MiB 0.0 MiB 1 env = None
24 51.4 MiB 0.8 MiB 1 env = Environment(envpath)
25 51.4 MiB 0.0 MiB 1 rm = RepositoryManager(env)
26 57.2 MiB 5.8 MiB 1 repos = rm.get_repository('')
27 159.5 MiB 102.3 MiB 1 repos.sync()
comment:5 by , 4 years ago
Thanks for sharing the profiling script. Seems best to go ahead with the proposed changes for 1.5.3.
comment:6 by , 4 years ago
I noticed root cause of that memory pool is not released during repository sync with Subversion repository. repos.ChangeCollector() instance is not finalized after it is passed to svn.delta.make_editor(). The class and the method are used in SubversionChangeset.get_changes().
Workaround is to clear editor.__dict__ for ref-count leak due to delta.make_editor().
Test script
# -*- coding: utf-8 -*- from svn import core, delta, fs, repos import sys import weakref def main(*args): pool = core.Pool(core.application_pool) repos_ptr = repos.open(args[0].encode('utf-8'), pool) fs_ptr = repos.fs(repos_ptr) do_replay(fs_ptr, 1, pool) def do_replay(fs_ptr, rev, pool): root_ptr = fs.revision_root(fs_ptr, rev, pool) editor = repos.ChangeCollector(fs_ptr, root_ptr, pool) editor_ref = weakref.ref(editor) e_ptr, e_baton = delta.make_editor(editor, pool) # repos.replay(root_ptr, e_ptr, e_baton, pool) del root_ptr, editor, e_ptr, e_baton assert editor_ref() is None if __name__ == '__main__': main(*sys.argv[1:])
Result
$ ~/venv/py39/bin/python fs-root.py ~/var/svn/genshi.edgewall.org Traceback (most recent call last): File "/home/jun66j5/src/tracdev/git/fs-root.py", line 70, in <module> main(*sys.argv[1:]) File "/home/jun66j5/src/tracdev/git/fs-root.py", line 12, in main do_replay(fs_ptr, 1, pool) File "/home/jun66j5/src/tracdev/git/fs-root.py", line 22, in do_replay assert editor_ref() is None AssertionError
New proposed changes in log:jomae.git@t13356-remove-pool-class.v2 (diff).
| Trac | Subversion | Increment on repos.sync()
|
|---|---|---|
| trunk | 1.14 | 21.9 MiB |
| t13356-remove-pool-class.v2 | 1.14 | 17.3 MiB |
comment:7 by , 4 years ago
Nice, that looks difficult to have tracked down. I ran the tests on macOS and they pass.
comment:8 by , 4 years ago
| Release Notes: | modified (diff) |
|---|---|
| Resolution: | → fixed |
| Status: | assigned → closed |
Committed in [17519].
The memory leak on repository sync has been reported in #13112,13129.
Note:
See TracTickets
for help on using tickets.
The exception
Exception TypeError: TypeError("'NoneType' object is not callable",) in <bound method apr_pool_t.__del__ of <libsvn.core.apr_pool_t; proxy of <Swig Object of type 'apr_pool_t *' at 0x7f52aeb14de0> >> ignoredwas also reported in #13261.