Hi,
Robert Kern wrote:
> % stats 20
> Thu Dec 4 18:51:19 2008 cython.prof
>
> 1092804 function calls (830642 primitive calls) in 2.267 CPU seconds
>
> Ordered by: internal time
> List reduced from 963 to 20 due to restriction <20>
>
> ncalls tottime percall cumtime percall filename:lineno(function)
> 8219 0.412 0.000 0.500 0.000 Scanning.py:401(next)
> 52164/15 0.347 0.000 1.286 0.086 Visitor.py:18(visit)
> 212836 0.242 0.000 0.242 0.000 {getattr}
> 52164/15 0.159 0.000 1.204 0.080 Visitor.py:138(visitchildren)
> 52149/23 0.136 0.000 1.204 0.052 Visitor.py:86(visitchild)
> 52164/15 0.135 0.000 1.204 0.080 Visitor.py:92(visitchildren)
> 1 0.047 0.047 0.073 0.073 Scanning.py:6(<module>)
> 52160 0.041 0.000 0.059 0.000 inspect.py:291(getmro)
> 4083 0.038 0.000 0.057 0.000 Symtab.py:273(declare)
> 36057/14 0.038 0.000 0.929 0.066 Visitor.py:179(visit_Node)
> 4000 0.029 0.000 0.160 0.000 Parsing.py:2066(p_c_enum_item)
> 4 0.029 0.007 0.029 0.007
> hashlib.py:55(__get_builtin_constructor)
> 52573 0.021 0.000 0.021 0.000 {isinstance}
> 4037 0.020 0.000 0.033 0.000
> Scanning.py:359(indentation_action)
> 117371 0.018 0.000 0.018 0.000 {method 'append' of 'list'
> objects}
> 52163 0.018 0.000 0.018 0.000 {hasattr}
> 8096 0.015 0.000 0.085 0.000 Actions.py:46(perform)
> 1 0.015 0.015 0.015 0.015 Regexps.py:9(<module>)
> 1 0.015 0.015 0.044 0.044 hashlib.py:52(<module>)
> 1 0.015 0.015 0.015 0.015 Annotate.py:3(<module>)
>
> It looks like a fair chunk of time is getting spent by the getattr() on line
> 26
> of Visitor.py:BasicVisitor.visit() because of missing entries in the
> dispatch_table. Per the comment there, that's possibly optimizable.
When you install Cython, it will compile the scanner, the parser and the
visitor module. That gives me the following for parsing a .pyx file that
contains only a ctypedef enum with 2000 entries.
--------------------------------
% stats 20
Fri Dec 5 08:39:55 2008 cython.prof
162946 function calls (159696 primitive calls) in 2.905 CPU seconds
Ordered by: internal time
List reduced from 828 to 20 due to restriction <20>
ncalls tottime percall cumtime percall filename:lineno(function)
3 0.456 0.152 0.573 0.191 {Parsing.p_module}
1 0.331 0.331 1.060 1.060 Main.py:5(<module>)
1 0.322 0.322 0.498 0.498 Code.py:5(<module>)
1 0.136 0.136 0.552 0.552 Main.py:77(create_pipeline)
1 0.080 0.080 2.905 2.905 {execfile}
1 0.078 0.078 0.078 0.078 __init__.py:71(search_function)
1 0.071 0.071 0.137 0.137 Builtin.py:5(<module>)
1 0.071 0.071 0.120 0.120 __init__.py:31(<module>)
1 0.069 0.069 2.825 2.825 cython:7(<module>)
3 0.056 0.019 0.191 0.064
TreeFragment.py:32(parse_from_strings)
1 0.043 0.043 0.183 0.183 inspect.py:25(<module>)
4094 0.042 0.000 0.066 0.000 Actions.py:46(perform)
2116 0.033 0.000 0.092 0.000 Symtab.py:278(declare)
1 0.033 0.033 0.230 0.230 ParseTreeTransforms.py:1(<module>)
1 0.032 0.032 0.032 0.032 collections.py:1(<module>)
1 0.031 0.031 0.031 0.031 hashlib.py:55(<module>)
2028/13 0.031 0.000 0.049 0.004
ParseTreeTransforms.py:75(visit_StatNode)
1 0.028 0.028 0.198 0.198
Code.py:380(commented_file_contents)
1 0.027 0.027 0.030 0.030
ParseTreeTransforms.py:162(visit_ModuleNode)
1 0.026 0.026 0.029 0.029 Annotate.py:3(<module>)
--------------------------------
It surprises me a bit that it calls p_module three times when parsing a
single .pyx file. Anyway, a single parser run takes 200 msecs even under
profiler control, which doesn't sound *that* unreasonable to me.
Stefan
_______________________________________________
Cython-dev mailing list
[email protected]
http://codespeak.net/mailman/listinfo/cython-dev
