introspection is slow and causes a significant memory leak #13057
Comments
|
comment:1
As another point of reference: If I run
the same thing now takes a second or two. |
|
comment:2
I did which, I thought, should reveal what is happening under the hood. However, I don't really understand the outcome: So, it seems much time is spent in the function "format". Has there been a change to that function recently? Or am I misinterpreting the figures (I am not sure if "cumtime" and "percall" include the time for calling sub-functions). |
|
comment:3
I'm not entirely sure what the output means either. This reminded me that there is some I had thought that most of the time taken by sage.misc.sageinspect.sage_getdoc might be taken up by sage.misc.sagedoc.detex, but that doesn't show up in the above at all, and I don't know what explains the extra 1.5 seconds. |
|
comment:4
Could you produce a similar report for sage-4.8? If the slow down happened in sage-5.0 the most likely candidate would be python itself. |
|
comment:5
Here are the various timings: |
|
comment:6
Replying to @ppurka:
Dropping the caches first is not a good way of timing this. The problem is not with disk access, but something else, so a better test is to get the docstring twice, and use the second timing. I now think that the change is should be in either 5.0beta7 or 5.0beta8... |
|
comment:7
Ok. Here they are again. Haven't dropped caches this time. The sage libraries are already loaded so, the |
|
comment:8
So it appears that the regression happened somewhere in 5.0beta8. #9128 seems like it touched a lot of stuff related to this, so it is a possible candidate for the cause of the regression. (Adding hivert to cc, since he was the author on that ticket.) |
|
comment:9
The sphinx ticket. That should be testable starting from beta7 and adding this single ticket. |
|
comment:10
There doesn't seem to be much of a difference from sage-4.7 (it is a different machine though) This test on sage-4.7 is done on a a virtual machine with 4 cpu cores and with 20G of memory. The earlier tests were done on my laptop with 2 cores (4 with HT) and with 4G of memory. |
|
comment:12
Replying to @ppurka:
Try running the sage_getdoc function a few times in a row with the same input on 4.7 and 5.0 (or just using the question mark) and you should see the difference. You really need to do it a few times in a row, though. The first time may be slow because it is reading from disk (a "warm cache" from starting up sage is not enough to prevent this) but it should not remain slow. |
|
comment:13
You are right. There is a slowdown indeed. |
|
comment:14
Just tested on sage-5.0beta7. The patch responsible for the slowdown is the second one from that ticket: |
|
comment:15
Perhaps it's the intersphinx invocation? Maybe we should disable that during introspection, and maybe the same for the dangling links. Something like this? diff --git a/doc/common/conf.py b/doc/common/conf.py
--- a/doc/common/conf.py
+++ b/doc/common/conf.py
@@ -608,14 +608,19 @@ def setup(app):
app.connect('autodoc-process-docstring', process_inherited)
app.connect('autodoc-skip-member', skip_member)
- app.add_config_value('intersphinx_mapping', {}, True)
- app.add_config_value('intersphinx_cache_limit', 5, False)
- # We do *not* fully initialize intersphinx since we call it by hand
- # in find_sage_dangling_links.
- # app.connect('missing-reference', missing_reference)
- app.connect('missing-reference', find_sage_dangling_links)
- import sphinx.ext.intersphinx
- app.connect('builder-inited', set_intersphinx_mappings)
- app.connect('builder-inited', sphinx.ext.intersphinx.load_mappings)
+ # When building the standard docs, app.srcdir is set to SAGE_DOC +
+ # 'LANGUAGE/DOCNAME', but when doing introspection, app.srcdir is
+ # set to a temporary directory. We don't want to use intersphinx,
+ # etc., when doing introspection.
+ if app.srcdir.startswith(SAGE_DOC):
+ app.add_config_value('intersphinx_mapping', {}, True)
+ app.add_config_value('intersphinx_cache_limit', 5, False)
+ # We do *not* fully initialize intersphinx since we call it by hand
+ # in find_sage_dangling_links.
+ # app.connect('missing-reference', missing_reference)
+ app.connect('missing-reference', find_sage_dangling_links)
+ import sphinx.ext.intersphinx
+ app.connect('builder-inited', set_intersphinx_mappings)
+ app.connect('builder-inited', sphinx.ext.intersphinx.load_mappings)
app.connect('builder-inited', nitpick_patch_config) |
|
comment:16
For me, without this change: With the change: |
|
Attachment: trac_13057-no-intersphinx.patch.gz |
|
comment:17
Here is essentially the above patch (although I've now also included the last line in the "if" block). Please test it from the command line and in the notebook, and you should probably also build the regular documentation and make sure it still looks okay. When I was testing this, I added a line to try to verify that app.srcdir is as I'm claiming in the patch (this applies on top of the attached patch): diff --git a/doc/common/conf.py b/doc/common/conf.py
--- a/doc/common/conf.py
+++ b/doc/common/conf.py
@@ -608,6 +608,8 @@ def setup(app):
app.connect('autodoc-process-docstring', process_inherited)
app.connect('autodoc-skip-member', skip_member)
+ print "************* %s **************" % app.srcdir
+
# When building the standard docs, app.srcdir is set to SAGE_DOC +
# 'LANGUAGE/DOCNAME', but when doing introspection, app.srcdir is
# set to a temporary directory. We don't want to use intersphinx,Florent: is this a good solution (i.e., not using intersphinx, etc., when doing introspection)? |
|
Author: John Palmieri |
|
comment:18
As I just reported on sage-devel, #9128 apparently also introduced a pretty large memory leak - every docstring lookup with "?" in the console leaks 56 MB of memory. This patch fixes the leak. |
kini
changed the title
|
comment:19
This patch seems to take care of my complaints nicely. I don't know what is actually going on with it, though, so I hope that someone who does know will give it a review. The 56 MB memory leak is worrying, though, and we should figure out why that was happening. Does someone know? |
|
comment:20
Should this ticket be priority critical? Users use introspection a lot, in my experience. This is not just some obscure memory leak. |
|
comment:21
Replying to @kini:
If this also solves the fact that building the doc now uses a HUGE amount of memory, I'd vote for this ticket being critical. |
|
comment:22
Nevermind, the doc building problem is already present in 4.8 so is completely unrelated, I mixed two different threads on sage-devel. |
|
comment:23
This is related to docbuilding using a lot of memory, but it doesn't solve that problem. It suggests that the problem comes from using intersphinx, and this might help someone track down the exact issue. Is there a ticket open for this issue? |
|
comment:24
I agree with Keshav: this ticket should have a higher priority. Any possible reviewers? |
|
comment:25
I can confirm that this patch works, and fixes all the issues raised here. But I know nothing about sphinx, so I am not sure about setting it to positive review. |
|
comment:26
Replying to @ppurka:
I wan't to have a close look at this one (understanding why there is a such a huge slowdown/memleak). It seems that the intersphinx database is recreated at each run (which is very bad wrt speed, caching the result should be doable) and not garbage collected (which is even worse). But I can't manage to find the time to do it. I is clearly critical or blocker. I'm soory, I didn't find the time to even apply the patch. Does it deactivate intersphinx when using Sorry that my machine is very fast and that I didn't notice the problem when writing #9128. Cheers, Florent |
|
comment:27
Before applying the patch, executing It should probably be of the form That is, the desired behavior is currently broken. After applying the patch, there is no link at all. So I would propose that we use this fix for now, since it speeds things up, prevents a memory leak, and doesn't disable anything which currently works. Then later when you have time, we can work on tracking down the memory leak, reinstating intersphinx in the notebook, and fixing the links so that they actually work. (Just fixing the link is, I think, currently unacceptable given the slowdown and the memory leak issues.) |
|
Reviewer: Keshav Kini |
|
comment:28
The leak is ridiculously bad. I'm going to give this positive review - whatever else this patch might do, it does fix that, at least. |
|
Merged: sage-5.1.beta5 |
Introspection used to be more or less immediate, and now something like
in the sage command line takes a few seconds.
"used to be" means that this slowdown happened sometime between 4.7.1 and 5.0, and probably between 4.8 and 5.0.
I don't know right now if we have the same regression in the notebook.
CC: @hivert
Component: documentation
Keywords: regression introspection
Author: John Palmieri
Reviewer: Keshav Kini
Merged: sage-5.1.beta5
Issue created by migration from https://trac.sagemath.org/ticket/13057
The text was updated successfully, but these errors were encountered: