Hello,
I've got some scripts which take quite a bit of time and I wanted to
investigate why they were so long. So I profiled them using cProfile
and I was quite surprised to get the following results. In short, SQL
queries themselves take less than 10% of the total time, and most of
the time is taken by SQLAlchemy itself (you'll notice than in the 50
first CPU consumers below, there isn't a single function of my own
application).
I should point out that this particular script doesn't manipulate that
many objects (a few thousands of them perhaps), and the queries aren't
complex at all. It would be good to know whether there are well known
techniques to help reduce the overall overhead of SQLAlchemy which, in
this case, is really bewildering.
Thank you
Antoine.
61307243 function calls (59670236 primitive calls) in 343.725
CPU seconds
Ordered by: internal time
List reduced from 1369 to 50 due to restriction <50>
ncalls tottime percall cumtime percall filename:lineno
(function)
23771 20.189 0.001 20.189 0.001 {method 'query' of
'_mysql.connection' objects}
4455901 9.244 0.000 9.244 0.000 {isinstance}
1736162 8.706 0.000 25.237 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:426
(collection)
23771 7.567 0.000 17.396 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/engine/base.py:1432
(_init_metadata)
1985456 6.111 0.000 10.047 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:342
(polymorphic_tasks)
288526 5.666 0.000 23.924 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:261
(visit_label)
53348 4.785 0.000 69.452 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/mapper.py:1190
(_save_obj)
316457 4.688 0.000 7.344 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:278
(visit_column)
2803666 4.359 0.000 4.359 0.000 {method 'get' of 'dict'
objects}
712463/23808 4.182 0.000 61.672 0.003 /usr/lib/python2.6/
site-packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/visitors.py:
49(_compiler_dispatch)
23771 3.595 0.000 3.595 0.000 {method 'store_result'
of '_mysql.connection' objects}
1095673 3.499 0.000 3.499 0.000 {hasattr}
712463/23808 3.446 0.000 61.827 0.003 /usr/lib/python2.6/
site-packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:
216(process)
13680 3.374 0.000 43.671 0.003 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:510
(visit_select)
10091 3.258 0.000 13.926 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:671
(_get_colparams)
10953 3.137 0.000 7.880 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/topological.py:162
(_sort)
246189 3.055 0.000 8.127 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/interfaces.py:592
(create_row_processor)
49248 2.992 0.000 9.442 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/mapper.py:1514
(_register_dependencies)
832076 2.951 0.000 2.951 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/state.py:49(dict)
205064 2.893 0.000 23.348 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:655
(preexecute)
651433 2.831 0.000 7.188 0.000 {method 'decode' of
'str' objects}
348681 2.771 0.000 6.485 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/interfaces.py:589
(setup)
1423203 2.687 0.000 3.681 0.000 {method 'add' of 'set'
objects}
829956 2.686 0.000 4.001 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:433
(elements)
1842480 2.657 0.000 2.657 0.000 {method 'append' of
'list' objects}
253492 2.637 0.000 6.252 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/attributes.py:1241
(from_attribute)
594870 2.618 0.000 3.582 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/interfaces.py:568
(__get_context_strategy)
291982 2.617 0.000 13.526 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/state.py:87
(get_history)
754720 2.613 0.000 6.251 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:437
(polymorphic_elements)
118594 2.608 0.000 2.608 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/util.py:721(values)
288526 2.564 0.000 4.196 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:488
(label_select_column)
1070557 2.554 0.000 2.557 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:1106
(quote)
316426 2.327 0.000 3.313 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:447
(_truncated_identifier)
441735 2.235 0.000 3.934 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/types.py:124
(dialect_impl)
13673 2.207 0.000 13.730 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/query.py:1959
(setup_context)
133921 2.206 0.000 29.651 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/query.py:1293
(instances)
651397 2.185 0.000 2.185 0.000 {_codecs.utf_8_decode}
41026 2.174 0.000 4.237 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/util.py:1090
(unique_list)
651397 2.172 0.000 4.358 0.000 /usr/lib64/python2.6/
encodings/utf_8.py:15(decode)
330640 2.135 0.000 2.675 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/compiler.py:423
(operator_string)
151781 2.109 0.000 2.544 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/expression.py:1935
(__init__)
629208 1.972 0.000 1.972 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/attributes.py:1051
(get_impl)
307596 1.906 0.000 10.107 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:441
(polymorphic_tosave_elements)
13680 1.903 0.000 10.286 0.001 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/sql/expression.py:3218
(__init__)
307596 1.850 0.000 9.449 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:445
(polymorphic_todelete_elements)
293765/232025 1.841 0.000 56.237 0.000 /usr/lib/python2.6/
site-packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/
attributes.py:354(get)
207147 1.840 0.000 3.282 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/strategies.py:113
(create_row_processor)
479136 1.811 0.000 1.811 0.000 /usr/lib64/python2.6/
weakref.py:242(__getitem__)
382082 1.771 0.000 12.761 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:171
(get_task_by_mapper)
205064 1.736 0.000 32.974 0.000 /usr/lib/python2.6/site-
packages/SQLAlchemy-0.5.4p2-py2.6.egg/sqlalchemy/orm/unitofwork.py:687
(execute)
--
You received this message because you are subscribed to the Google Groups
"sqlalchemy" 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/sqlalchemy?hl=en.
