Sage: Ticket #11734: sage_wraps should only read the sources of wrapped functions when needed.
https://trac.sagemath.org/ticket/11734
<p>
According to private conversation with Francois Bissey, <a class="closed ticket" href="https://trac.sagemath.org/ticket/9976" title="enhancement: Decorated functions/methods have generic signature in documentation (closed: fixed)">#9976</a> has introduced a problem that makes it impossible start sage-4.7.1 on Gentoo. That's pretty serious, and so this ticket is a blocker.
</p>
<p>
The problem is that sage_wraps reads the sources of to-be-wrapped functions and methods. The sources are stored as an attribute to the wrapper, which, on the one hand, is a waste of memory. Worse: Reading the Cython sources is impossible for sage-on-gentoo. Therefore, sage can't start.
</p>
<p>
My patch introduces some lightweight classes, that simply store a reference to an object (e.g., the to-be-wrapped function) and return the sources or source lines or the argument list <em>only when called</em>.
</p>
<hr />
<p>
Apply only <a class="attachment" href="https://trac.sagemath.org/attachment/ticket/11734/trac11734_sage_wraps_no_sourceread_lambda.proper.patch" title="Attachment 'trac11734_sage_wraps_no_sourceread_lambda.proper.patch' in Ticket #11734">trac11734_sage_wraps_no_sourceread_lambda.proper.patch</a><a class="trac-rawlink" href="https://trac.sagemath.org/raw-attachment/ticket/11734/trac11734_sage_wraps_no_sourceread_lambda.proper.patch" title="Download"></a> to the Sage library.
</p>
en-usSagehttps://trac.sagemath.org/chrome/site/logo_sagemath_trac.png
https://trac.sagemath.org/ticket/11734
Trac 1.1.6SimonKingWed, 24 Aug 2011 08:14:53 GMTattachment set
https://trac.sagemath.org/ticket/11734
https://trac.sagemath.org/ticket/11734
<ul>
<li><strong>attachment</strong>
set to <em>trac11734_sage_wraps_no_sourceread.patch</em>
</li>
</ul>
<p>
sage_wraps should only read source files when needed.
</p>
TicketSimonKingWed, 24 Aug 2011 08:26:55 GMTstatus changed
https://trac.sagemath.org/ticket/11734#comment:1
https://trac.sagemath.org/ticket/11734#comment:1
<ul>
<li><strong>status</strong>
changed from <em>new</em> to <em>needs_review</em>
</li>
</ul>
<p>
The patch should solve the problem with prematurely reading sources on gentoo. However, I can not test it, myself. Francois, can you verify it?
</p>
<p>
<strong><span class="underline">Benefits</span></strong>
</p>
<p>
<span class="underline">Startuptime</span>
</p>
<p>
The startuptime did slightly improve (but perhaps that is not significant):
</p>
<p>
Without patch
</p>
<pre class="wiki">$ ./sage -startuptime
== Tree ==
sage.all: 1.132 (None)
...
</pre><p>
With patch
</p>
<pre class="wiki">$ ./sage -startuptime
== Tree ==
sage.all: 1.045 (None)
</pre><p>
<span class="underline">Memory</span>
</p>
<p>
The memory consumption improved as well:
</p>
<p>
Without patch:
</p>
<pre class="wiki">sage: get_memory_usage()
861.2890625
</pre><p>
With patch:
</p>
<pre class="wiki">sage: get_memory_usage()
861.234375
</pre><p>
<span class="underline">Bugfix</span>
</p>
<p>
Not reading the sources when a function is wrapped has an additional benefit: If one interactively defines a lambda function and wraps it, then the source is not available. Hence, the following example (that is a new doctest) used to fail:
</p>
<pre class="wiki"> sage: def square(f):
... @sage_wraps(f)
... def new_f(x):
... return f(x)*f(x)
... return new_f
...
sage: f = lambda x:x^2
sage: g = square(f)
sage: g(3)
81
</pre><p>
Without the patch, the last line fails with a mysterious attribute error (the user would certainly have not easily been able to track the problem down).
</p>
TicketSimonKingWed, 24 Aug 2011 08:27:36 GMTkeywords changed
https://trac.sagemath.org/ticket/11734#comment:2
https://trac.sagemath.org/ticket/11734#comment:2
<ul>
<li><strong>keywords</strong>
<em>startuptime</em> added
</li>
</ul>
TicketsaraedumWed, 24 Aug 2011 17:08:34 GMT
https://trac.sagemath.org/ticket/11734#comment:3
https://trac.sagemath.org/ticket/11734#comment:3
<p>
I do not fully understand your patch. How does it differ from simply taking out the call to sage_getargspec and moving it into a lambda? (see my attached patch)
</p>
<p>
Btw. On my install of sage-4.7.2alpha2 the doctest described in <em>Bugfix</em> does not fail.
</p>
TicketSimonKingWed, 24 Aug 2011 17:18:42 GMT
https://trac.sagemath.org/ticket/11734#comment:4
https://trac.sagemath.org/ticket/11734#comment:4
<p>
Replying to <a class="ticket" href="https://trac.sagemath.org/ticket/11734#comment:3" title="Comment 3">saraedum</a>:
</p>
<blockquote class="citation">
<p>
I do not fully understand your patch. How does it differ from simply taking out the call to sage_getargspec and moving it into a lambda? (see my attached patch)
</p>
</blockquote>
<p>
If I remember correctly, I once tried that approach. The line <code>argspec = sage_getargspec(wrapped)</code> was introduced for a reason (something went wrong), but I can't remember what it was.
</p>
<p>
Did you run full tests with your patch?
</p>
<blockquote class="citation">
<p>
Btw. On my install of sage-4.7.2alpha2 the doctest described in <em>Bugfix</em> does not fail.
</p>
</blockquote>
<p>
Really? Strange. It failed for me both with sage-4.7.2.alpha1 and with sage-4.6.2.
</p>
TicketSimonKingWed, 24 Aug 2011 17:57:23 GMT
https://trac.sagemath.org/ticket/11734#comment:5
https://trac.sagemath.org/ticket/11734#comment:5
<p>
The tests in sage/misc pass with your patch, and the example from my post above (the "bugfix") works as well.
</p>
<p>
If all tests pass, then you patch should be preferred.
</p>
<p>
It turned out that I am not to blame for the "argspec = sage_getargspec(wrapped)". The first author of <a class="closed ticket" href="https://trac.sagemath.org/ticket/9976" title="enhancement: Decorated functions/methods have generic signature in documentation (closed: fixed)">#9976</a> had introduced an alternative approach to provide the argument list when building the documentation -- and I think what we have here is an artefact of that approach.
</p>
<p>
Since it was about documentation: Could you please build the documentation with your patch (I will only be able to do so tomorrow) and look whether the list of arguments of functions and methods created with @sage_wraps are correct in the reference manual? See, for example, the interreduced_basis method of multivariate polynomial ideals.
</p>
TicketSimonKingWed, 24 Aug 2011 18:00:51 GMT
https://trac.sagemath.org/ticket/11734#comment:6
https://trac.sagemath.org/ticket/11734#comment:6
<p>
PS: Even though the example from my previous post does not fail on your machine (for reasons that I don't understand), it did fail for me. Hence, I think it would make sense to include that example into your patch (you can of course simply copy the example from my patch).
</p>
TicketsaraedumWed, 24 Aug 2011 18:11:18 GMT
https://trac.sagemath.org/ticket/11734#comment:7
https://trac.sagemath.org/ticket/11734#comment:7
<p>
I ran the doctests without long and they passed. Let me try to build the reference manual.
</p>
TicketsaraedumWed, 24 Aug 2011 19:21:30 GMT
https://trac.sagemath.org/ticket/11734#comment:8
https://trac.sagemath.org/ticket/11734#comment:8
<p>
The reference manual seems ok. For example I get <em>complete_primary_decomposition(algorithm='sy')</em> which is a method with the <em> @libsingular_standard_options</em> decorator.
</p>
TicketSimonKingWed, 24 Aug 2011 19:34:02 GMTdescription changed
https://trac.sagemath.org/ticket/11734#comment:9
https://trac.sagemath.org/ticket/11734#comment:9
<ul>
<li><strong>description</strong>
modified (<a href="/ticket/11734?action=diff&version=9">diff</a>)
</li>
</ul>
<p>
I can confirm that the doc tests pass. I can also confirm that your patch provides a similar (small) positive side effect (comparable to what I stated on my patch) on startuptime and memory consumption.
</p>
<p>
Please add the above "bugfix" example to your patch. In the author field, please replace my name by yours.
</p>
TicketwasWed, 24 Aug 2011 23:31:04 GMTkeywords changed
https://trac.sagemath.org/ticket/11734#comment:10
https://trac.sagemath.org/ticket/11734#comment:10
<ul>
<li><strong>keywords</strong>
<em>sd32</em> added
</li>
</ul>
TicketfbisseyThu, 25 Aug 2011 01:24:09 GMT
https://trac.sagemath.org/ticket/11734#comment:11
https://trac.sagemath.org/ticket/11734#comment:11
<p>
Hi, I had to take a bit more rest than I expected - exhaustion is bad for you :)
</p>
<p>
I have just tested this patch in 4.7.2.alpha2 and it works. I think Simon has not made clear the fact that my original report was about the sage on gentoo distribution. It still meant that sage was looking at some cython files before starting up, which can't be good for the startup time.
</p>
TicketSimonKingThu, 25 Aug 2011 06:46:56 GMT
https://trac.sagemath.org/ticket/11734#comment:12
https://trac.sagemath.org/ticket/11734#comment:12
<p>
Replying to <a class="ticket" href="https://trac.sagemath.org/ticket/11734#comment:11" title="Comment 11">fbissey</a>:
</p>
<blockquote class="citation">
<p>
I have just tested this patch in 4.7.2.alpha2 and it works.
</p>
</blockquote>
<p>
You mean, it would definitely fix the Gentoo problem?
</p>
<blockquote class="citation">
<p>
I think Simon has not made clear the fact that my original report was about the sage on gentoo distribution.
</p>
</blockquote>
<p>
The ticket description states "introduced a problem that makes it impossible start sage-4.7.1 on Gentoo." I thought that it <em>is</em> clear enough.
</p>
<blockquote class="citation">
<p>
It still meant that sage was looking at some cython files before starting up, which can't be good for the startup time.
</p>
</blockquote>
<p>
Yep. Actually I have tested (by inserting print statements in the functions that read the sources for auto-inspection) that no file is read at startup, with the patch.
</p>
TicketSimonKingThu, 25 Aug 2011 07:02:28 GMTreviewer set; author deleted
https://trac.sagemath.org/ticket/11734#comment:13
https://trac.sagemath.org/ticket/11734#comment:13
<ul>
<li><strong>reviewer</strong>
set to <em>Simon King</em>
</li>
<li><strong>author</strong>
<em>Simon King</em> deleted
</li>
</ul>
<p>
Concerning documentation: It looks very nice!
</p>
<p>
Just for testing, I had inserted a function with a complicated argument list, and put it under the @singular_standard_options decorator:
</p>
<pre class="wiki">@singular_standard_options
def MyTestFunc(bla, blubb, bar={'bla':{1:2}}, foo=None, **kwds):
"""
This is just a test
"""
return
</pre><p>
It is shown in the reference manual exactly as it should.
</p>
<p>
In addition, the doc tests pass, the startup time seems to slightly improve (perhaps not significantly), and the memory consumption decreases a little.
</p>
<p>
I hope I understood correctly that it will fix the problem on gentoo.
</p>
<p>
In general, if a bug is fixed, it should be demonstrated by a new doc test. The example that I gave above <em>does</em> fail (at least for me) without the patch. So, I think it should be included. If nobody beats me to it, I'd provide that example in a referee patch.
</p>
<p>
Also I don't know the real name of saraedum. So, please insert the name in the Author field.
</p>
<p>
Apart from that, it is a positive review.
</p>
TicketsaraedumThu, 25 Aug 2011 07:14:18 GMTauthor set
https://trac.sagemath.org/ticket/11734#comment:14
https://trac.sagemath.org/ticket/11734#comment:14
<ul>
<li><strong>author</strong>
set to <em>Julian Rueth</em>
</li>
</ul>
TicketsaraedumThu, 25 Aug 2011 07:17:12 GMT
https://trac.sagemath.org/ticket/11734#comment:15
https://trac.sagemath.org/ticket/11734#comment:15
<p>
I'm not sure if I misunderstand what you mean to say with 'significantly' but the average startuptime does actually improve with that patch. (I would provide some data but can't reach the machine where that data is stored right now)
</p>
TicketSimonKingThu, 25 Aug 2011 07:24:06 GMT
https://trac.sagemath.org/ticket/11734#comment:16
https://trac.sagemath.org/ticket/11734#comment:16
<p>
Replying to <a class="ticket" href="https://trac.sagemath.org/ticket/11734#comment:15" title="Comment 15">saraedum</a>:
</p>
<blockquote class="citation">
<p>
I'm not sure if I misunderstand what you mean to say with 'significantly'
</p>
</blockquote>
<p>
There is the "sage -startuptime" script. It prints a lot of data, but the time for importing sage.all is most important, as much as I understood.
</p>
<p>
Without the patch, I get with sage-4.7.2.alpha2:
</p>
<pre class="wiki">== Slowest (including children) ==
1.242 sage.all (None)
</pre><p>
With the patch, I get:
</p>
<h2 id="Slowestincludingchildren">Slowest (including children)</h2>
<p>
1.133 sage.all (None)
}}}
</p>
<p>
However, these times are a little flaky. So, I don't know if we can call it significant if the difference is 10%.
</p>
<p>
Concerning the additional test: It is a bit strange. It turned out that it <em>does</em> fail when I execute it on command line, but it does <em>not</em> fail (even without your patch) when it is a doc test. Apparently, in a doc test, Sage is able to find the function definition, which is impossible on the command line.
</p>
TicketsaraedumThu, 25 Aug 2011 07:33:14 GMT
https://trac.sagemath.org/ticket/11734#comment:17
https://trac.sagemath.org/ticket/11734#comment:17
<p>
Anyway, I would leave the doctest in; probably we should add a comment, describing this difference.
Btw. I use dumbbench and a <em>silenced</em> version of startuptime to make sure that I'm not only seeing random speedups.
</p>
<p>
The speedup is actually a little bit mysterious. It occurs once you remove a few <em>sage_wraps</em> decorators. Apparently python's <em>inspect.<a class="missing wiki">ArgSpec?</a></em> does something smart once it gets called very often (to speed up things?) which results in a slowdown in our case.
</p>
TicketSimonKingThu, 25 Aug 2011 07:45:43 GMT
https://trac.sagemath.org/ticket/11734#comment:18
https://trac.sagemath.org/ticket/11734#comment:18
<p>
Replying to <a class="ticket" href="https://trac.sagemath.org/ticket/11734#comment:17" title="Comment 17">saraedum</a>:
</p>
<blockquote class="citation">
<p>
Anyway, I would leave the doctest in; probably we should add a comment, describing this difference.
</p>
</blockquote>
<p>
OK, please do!
</p>
<blockquote class="citation">
<p>
The speedup is actually a little bit mysterious. It occurs once you remove a few <em>sage_wraps</em> decorators. Apparently python's <em>inspect.<a class="missing wiki">ArgSpec?</a></em> does something smart once it gets called very often (to speed up things?) which results in a slowdown in our case.
</p>
</blockquote>
<p>
You removed a few sage_wraps for a test?
</p>
<p>
Actually I find the speedup not mysterious. The 10% are just with your patch, i.e., I did not additionally remove sage_wraps. And the reason for the speedup is clear: Python's <code>inspect.getargspec</code> is insufficient for Sage. It can not deal with Cython functions, and of course it can not understand the special wrappers in Sage:
</p>
<pre class="wiki">sage: import inspect
sage: cython('cpdef f(a,b,c=None): pass')
sage: inspect.getargspec(f)
---------------------------------------------------------------------------
TypeError Traceback (most recent call last)
/mnt/local/king/SAGE/sage-4.7.2.alpha2/devel/sage-main/<ipython console> in <module>()
/mnt/local/king/SAGE/sage-4.7.2.alpha2/local/lib/python/inspect.pyc in getargspec(func)
801 func = func.im_func
802 if not isfunction(func):
--> 803 raise TypeError('arg is not a Python function')
804 args, varargs, varkw = getargs(func.func_code)
805 return ArgSpec(args, varargs, varkw, func.func_defaults)
TypeError: arg is not a Python function
</pre><p>
and similarly
</p>
<pre class="wiki">sage: P.<x,y,z> = QQ[]
sage: I = P*[x,y]
sage: inspect.getargspec(I.interreduced_basis)
ArgSpec(args=[], varargs='args', keywords='kwds', defaults=None)
sage: inspect.getargspec(I.groebner_basis)
---------------------------------------------------------------------------
TypeError Traceback (most recent call last)
/mnt/local/king/SAGE/sage-4.7.2.alpha2/devel/sage-main/<ipython console> in <module>()
/mnt/local/king/SAGE/sage-4.7.2.alpha2/local/lib/python/inspect.pyc in getargspec(func)
801 func = func.im_func
802 if not isfunction(func):
--> 803 raise TypeError('arg is not a Python function')
804 args, varargs, varkw = getargs(func.func_code)
805 return ArgSpec(args, varargs, varkw, func.func_defaults)
TypeError: arg is not a Python function
</pre><p>
while the Sage autoinspection finds
</p>
<pre class="wiki">sage: from sage.misc.sageinspect import sage_getargspec
sage: sage_getargspec(I.interreduced_basis)
ArgSpec(args=['self'], varargs=None, keywords=None, defaults=None)
sage: sage_getargspec(I.groebner_basis)
ArgSpec(args=['self', 'algorithm', 'deg_bound', 'mult_bound', 'prot'], varargs='args', keywords='kwds', defaults=('', None, None, False))
</pre><p>
In the most difficult cases, <code>sage_getargspec</code> actually needs to read the source (using <code>sage_getsourcelines</code>) and analyse the function definition. That's why inspect.getargspec is faster (yet a lot less powerful) than sage.misc.sageinspect.sage_getargspec.
</p>
TicketsaraedumThu, 25 Aug 2011 07:52:40 GMT
https://trac.sagemath.org/ticket/11734#comment:19
https://trac.sagemath.org/ticket/11734#comment:19
<p>
I spend quite a bit of time looking at that speedup yesterday. While everything you say is certainly correct, a big part comes from calling the constructor I mentioned less frequently. It turned out that removing the decorator from <em>any</em> interacts control would almost yield the same speedup - even though the that control is never referenced in the --startuptime call.
If I trust cProfile then there is a single call to the <a class="missing wiki">ArgSpec?</a> constructor that is slow after a certain number of calls. Maybe cProfile is misleading here, and actually something else is happening...anyway, it's faster now, I don't think it introduces any new bug, so I'm happy with the result ;)
</p>
TicketsaraedumThu, 25 Aug 2011 07:56:40 GMTattachment set
https://trac.sagemath.org/ticket/11734
https://trac.sagemath.org/ticket/11734
<ul>
<li><strong>attachment</strong>
set to <em>trac11734_sage_wraps_no_sourceread_lambda.patch</em>
</li>
</ul>
TicketSimonKingThu, 25 Aug 2011 09:41:39 GMTstatus changed
https://trac.sagemath.org/ticket/11734#comment:20
https://trac.sagemath.org/ticket/11734#comment:20
<ul>
<li><strong>status</strong>
changed from <em>needs_review</em> to <em>positive_review</em>
</li>
</ul>
<p>
With the new patch, all tests pass, and for the reasons mentioned previously it is a positive review.
</p>
TicketleifThu, 08 Sep 2011 10:44:51 GMTdescription changed
https://trac.sagemath.org/ticket/11734#comment:21
https://trac.sagemath.org/ticket/11734#comment:21
<ul>
<li><strong>description</strong>
modified (<a href="/ticket/11734?action=diff&version=21">diff</a>)
</li>
</ul>
TicketSimonKingTue, 13 Sep 2011 09:03:06 GMT
https://trac.sagemath.org/ticket/11734#comment:22
https://trac.sagemath.org/ticket/11734#comment:22
<p>
For the patchbot:
</p>
<p>
Apply trac11734_sage_wraps_no_sourceread_lambda.patch
</p>
TicketleifSat, 17 Sep 2011 05:20:55 GMTstatus changed; resolution, merged set
https://trac.sagemath.org/ticket/11734#comment:23
https://trac.sagemath.org/ticket/11734#comment:23
<ul>
<li><strong>status</strong>
changed from <em>positive_review</em> to <em>closed</em>
</li>
<li><strong>resolution</strong>
set to <em>fixed</em>
</li>
<li><strong>merged</strong>
set to <em>sage-4.7.2.alpha3</em>
</li>
</ul>
TicketleifWed, 28 Sep 2011 16:59:56 GMTattachment set
https://trac.sagemath.org/ticket/11734
https://trac.sagemath.org/ticket/11734
<ul>
<li><strong>attachment</strong>
set to <em>trac11734_sage_wraps_no_sourceread_lambda.proper.patch</em>
</li>
</ul>
<p>
"Proper" Mercurial changeset replacement patch.
</p>
TicketleifWed, 28 Sep 2011 17:01:18 GMTdescription changed
https://trac.sagemath.org/ticket/11734#comment:24
https://trac.sagemath.org/ticket/11734#comment:24
<ul>
<li><strong>description</strong>
modified (<a href="/ticket/11734?action=diff&version=24">diff</a>)
</li>
</ul>
<p>
I've attached a <code>*.proper.patch</code>, which is identical except that I removed the "garbage" before "<code># HG changeset patch</code>", i.e., I deleted the first line "<code>exporting patch:</code>", since Jeroen's current merger rejects such patches.
</p>
<p>
For now, please make sure all your patches start with "<code># HG changeset patch</code>", i.e., have it on the first line without any preceding messages or whatever.
</p>
<p>
I've relaxed that in <em>my version</em> of the merger, but Jeroen and maybe others are likely to use his more restrictive one.
</p>
Ticket