#13057: introspection is slow
--------------------------------------------+-------------------------------
Reporter: bober | Owner: mvngu
Type: defect | Status: new
Priority: major | Milestone: sage-5.1
Component: documentation | Resolution:
Keywords: regression introspection | Work issues:
Report Upstream: N/A | Reviewers:
Authors: | Merged in:
Dependencies: | Stopgaps:
--------------------------------------------+-------------------------------
Comment (by SimonKing):
I did
{{{
sage: from sage.misc.sageinspect import sage_getdoc
sage: %prun L = sage_getdoc(gcd)
}}}
which, I thought, should reveal what is happening under the hood.
However, I don't really understand the outcome:
{{{
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.286 0.286 1.269 1.269
intersphinx.py:74(read_inventory_v2)
20751 0.272 0.000 0.576 0.000
intersphinx.py:90(split_lines)
28708 0.215 0.000 0.327 0.000 posixpath.py:60(join)
2 0.179 0.089 0.179 0.090 {cPickle.dump}
73 0.123 0.002 0.123 0.002 {method 'search' of
'_sre.SRE_Pattern' objects}
1 0.108 0.108 0.536 0.536
intersphinx.py:53(read_inventory_v1)
36194 0.099 0.000 0.099 0.000 {method 'setdefault' of
'dict' objects}
81003/79947 0.097 0.000 0.100 0.000 {len}
20758 0.095 0.000 0.246 0.000 {method 'decode' of 'str'
objects}
26193 0.093 0.000 0.093 0.000 {_codecs.utf_8_decode}
1461/328 0.089 0.000 0.356 0.001 sre_parse.py:379(_parse)
7914 0.089 0.000 0.252 0.000 codecs.py:503(readline)
20238 0.086 0.000 0.125 0.000 sre_parse.py:182(__next)
2972/1056 0.084 0.000 0.093 0.000 sre_parse.py:140(getwidth)
28718 0.077 0.000 0.077 0.000 {method 'split' of 'unicode'
objects}
20756 0.076 0.000 0.151 0.000 utf_8.py:15(decode)
5444 0.066 0.000 0.115 0.000 codecs.py:424(read)
29 0.064 0.002 0.118 0.004
sre_compile.py:301(_optimize_unicode)
2344/286 0.060 0.000 0.259 0.001 sre_compile.py:32(_compile)
28665 0.059 0.000 0.059 0.000 {method 'startswith' of
'unicode' objects}
18416 0.057 0.000 0.057 0.000 {method 'read' of 'file'
objects}
26193 0.053 0.000 0.053 0.000 {method 'endswith' of
'unicode' objects}
28717 0.052 0.000 0.052 0.000 {method 'endswith' of 'str'
objects}
41439 0.049 0.000 0.049 0.000 {method 'append' of 'list'
objects}
28826 0.048 0.000 0.048 0.000 {method 'rstrip' of
'unicode' objects}
17769 0.045 0.000 0.154 0.000 sre_parse.py:201(get)
21097 0.045 0.000 0.045 0.000 {method 'find' of 'str'
objects}
688 0.034 0.000 0.174 0.000
sre_compile.py:207(_optimize_charset)
7914 0.034 0.000 0.286 0.000 codecs.py:612(next)
10021 0.030 0.000 0.046 0.000
sre_parse.py:130(__getitem__)
1 0.027 0.027 0.115 0.115 pickle.py:845(load)
266 0.021 0.000 0.025 0.000
sre_compile.py:258(_mk_bitmap)
13462 0.021 0.000 0.021 0.000 {isinstance}
2766 0.017 0.000 0.030 0.000 pickle.py:929(load_binint1)
5499 0.015 0.000 0.015 0.000 {method 'splitlines' of
'unicode' objects}
918/288 0.015 0.000 0.361 0.001 sre_parse.py:301(_parse_sub)
7445 0.014 0.000 0.028 0.000 sre_parse.py:195(match)
23 0.013 0.001 0.013 0.001 {built-in method decompress}
4694 0.012 0.000 0.018 0.000 sre_parse.py:138(append)
1379 0.011 0.000 0.019 0.000
pickle.py:1173(load_long_binput)
8237 0.010 0.000 0.010 0.000 {ord}
66 0.009 0.000 0.015 0.000 optparse.py:1007(add_option)
3832 0.009 0.000 0.013 0.000 sre_parse.py:126(__len__)
3232 0.009 0.000 0.013 0.000 token.py:43(__hash__)
2 0.009 0.004 0.009 0.004 {posix.popen}
688 0.008 0.000 0.186 0.000
sre_compile.py:178(_compile_charset)
934 0.008 0.000 0.801 0.001 re.py:228(_compile)
286 0.008 0.000 0.150 0.001
sre_compile.py:361(_compile_info)
5 0.008 0.002 0.028 0.006 style.py:17(__new__)
1485/27 0.008 0.000 0.011 0.000 nodes.py:189(_fast_traverse)
5253 0.008 0.000 0.008 0.000 {min}
269 0.007 0.000 0.007 0.000 {method 'update' of 'dict'
objects}
4114 0.007 0.000 0.011 0.000 {method 'get' of 'dict'
objects}
13 0.006 0.000 0.345 0.027 __init__.py:10(<module>)
1 0.006 0.006 0.011 0.011 nodes.py:20(<module>)
1 0.005 0.005 0.494 0.494 application.py:12(<module>)
5 0.005 0.001 0.327 0.065 application.py:351(add_node)
19/18 0.005 0.000 0.289 0.016 {__import__}
1 0.005 0.005 0.227 0.227 states.py:101(<module>)
588 0.005 0.000 0.005 0.000 re.py:206(escape)
2388 0.004 0.000 0.004 0.000 sre_parse.py:90(__init__)
3206 0.004 0.000 0.004 0.000
sre_compile.py:24(_identityfunction)
688 0.004 0.000 0.048 0.000
statemachine.py:690(make_transition)
732 0.004 0.000 0.008 0.000 sre_compile.py:354(_simple)
286 0.004 0.000 0.789 0.003 sre_compile.py:495(compile)
3232 0.004 0.000 0.004 0.000 {hash}
248 0.004 0.000 0.004 0.000 {built-in method __new__ of
type object at 0x7fa2a2015f60}
507 0.004 0.000 0.006 0.000
sre_parse.py:225(_class_escape)
288/286 0.003 0.000 0.371 0.001 sre_parse.py:663(parse)
1919 0.003 0.000 0.003 0.000 {marshal.loads}
614 0.003 0.000 0.005 0.000 sre_parse.py:257(_escape)
1841 0.003 0.000 0.003 0.000 {repr}
120 0.003 0.000 0.052 0.000
statemachine.py:723(make_transitions)
917 0.003 0.000 0.792 0.001 re.py:188(compile)
3 0.003 0.001 0.059 0.020 __init__.py:11(<module>)
350 0.003 0.000 0.004 0.000 token.py:15(split)
3 0.003 0.001 0.097 0.032 html.py:10(<module>)
2211 0.003 0.000 0.003 0.000 {method 'extend' of 'list'
objects}
1782 0.003 0.000 0.003 0.000 {setattr}
1065 0.002 0.000 0.003 0.000 {hasattr}
861 0.002 0.000 0.002 0.000 pickle.py:1006(load_tuple2)
286 0.002 0.000 0.411 0.001 sre_compile.py:480(_code)
1 0.002 0.002 0.019 0.019 agile.py:10(<module>)
1 0.002 0.002 0.238 0.238 __init__.py:68(<module>)
1040 0.002 0.000 0.002 0.000 {method 'join' of 'str'
objects}
345 0.002 0.000 0.003 0.000 pickle.py:933(load_binint2)
1 0.002 0.002 0.310 0.310 latex.py:13(<module>)
572 0.002 0.000 0.003 0.000 sre_compile.py:474(isstring)
1202 0.002 0.000 0.002 0.000 {getattr}
468 0.002 0.000 0.003 0.000
pickle.py:1014(load_empty_list)
4 0.002 0.000 0.002 0.000 {posix.remove}
594 0.002 0.000 0.002 0.000 {range}
233 0.002 0.000 0.004 0.000 pickle.py:1185(load_appends)
203 0.002 0.000 0.003 0.000 other.py:986(_shortened)
1 0.002 0.002 0.168 0.168 environment.py:10(<module>)
...
1 0.000 0.000 0.000 0.000 references.py:7(<module>)
1 0.000 0.000 0.000 0.000 universal.py:13(<module>)
1 0.000 0.000 3.304 3.304 sagedoc.py:333(format)
8 0.000 0.000 0.000 0.000 {_bisect.insort}
70 0.000 0.000 0.000 0.000 __init__.py:41(__init__)
...
}}}
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).
--
Ticket URL: <http://trac.sagemath.org/sage_trac/ticket/13057#comment:2>
Sage <http://www.sagemath.org>
Sage: Creating a Viable Open Source Alternative to Magma, Maple, Mathematica,
and MATLAB
--
You received this message because you are subscribed to the Google Groups
"sage-trac" group.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to
[email protected].
For more options, visit this group at
http://groups.google.com/group/sage-trac?hl=en.
