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 sqlalch...@googlegroups.com. To unsubscribe from this group, send email to sqlalchemy+unsubscr...@googlegroups.com. For more options, visit this group at http://groups.google.com/group/sqlalchemy?hl=en.