On Feb 24, 2006, at 11:39 AM, Michael Bayer wrote:
oh thats pretty weird, what is the actual codepath being executed
during this test ? they seem completely different.
Hmm. I'll need to do some more research there. I'm not doing anything
unusual that I know of, just mapping my tables/classes with
assign_mapper. All I did was start my app, wait for the
initialization to be finished, then close it again (I profiled the
entire app, not just SQLAlchemy). I did exactly the same thing on
both profiles (before (r1019) and after (r1025)). Remember this is a
GUI app, so there's a lot more going on at startup than just mapping
SQLAlchemy tables to classes.
Here's another comparison. This time all I'm doing is importing my
model.py module, which declares all my tables, classes, and mappings.
Before (SVN r1019):
7601 function calls (5985 primitive calls) in 2.100 CPU
seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
...
1 0.000 0.000 0.000 0.000 schema.py:104(__init__)
1 0.010 0.010 0.270 0.270 schema.py:16(?)
1 0.000 0.000 0.000 0.000 schema.py:214(Column)
2 0.000 0.000 0.000 0.000 schema.py:216(__init__)
1 0.000 0.000 0.000 0.000 schema.py:26(SchemaItem)
1 0.000 0.000 1.370 1.370 schema.py:28(_init_items)
1 0.000 0.000 1.370 1.370 schema.py:282
(_set_parent)
1 0.000 0.000 0.000 0.000 schema.py:353(ForeignKey)
1 0.000 0.000 0.000 0.000 schema.py:422
(DefaultGenerator)
1 0.000 0.000 0.000 0.000 schema.py:431
(PassiveDefault)
1 0.000 0.000 0.000 0.000 schema.py:440
(ColumnDefault)
1 0.000 0.000 0.000 0.000 schema.py:451(Sequence)
1 0.000 0.000 0.000 0.000 schema.py:468(Index)
989/1 1.370 0.001 1.370 1.370 schema.py:49(__getattr__)
1 0.000 0.000 0.000 0.000 schema.py:515
(SchemaEngine)
1 0.000 0.000 0.000 0.000 schema.py:534
(SchemaVisitor)
1 0.000 0.000 0.000 0.000 schema.py:56
(_get_table_key)
1 0.000 0.000 0.000 0.000 schema.py:64
(TableSingleton)
1 0.000 0.000 1.370 1.370 schema.py:66(__call__)
1 0.000 0.000 0.000 0.000 schema.py:98(Table)
...
After (SVN r1025):
14108 function calls (13316 primitive calls) in 1.050 CPU
seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
...
12 0.000 0.000 0.000 0.000 schema.py:104(__init__)
1 0.030 0.030 0.310 0.310 schema.py:16(?)
12 0.010 0.001 0.010 0.001 schema.py:188
(accept_visitor)
1 0.000 0.000 0.000 0.000 schema.py:214(Column)
105 0.000 0.000 0.000 0.000 schema.py:216(__init__)
1 0.000 0.000 0.000 0.000 schema.py:26(SchemaItem)
343 0.010 0.000 0.010 0.000 schema.py:261(<lambda>)
53 0.000 0.000 0.000 0.000 schema.py:263(<lambda>)
81/16 0.000 0.000 0.060 0.004 schema.py:28(_init_items)
65 0.010 0.000 0.060 0.001 schema.py:282
(_set_parent)
40 0.030 0.001 0.050 0.001 schema.py:309
(_make_proxy)
227 0.010 0.000 0.010 0.000 schema.py:328
(accept_visitor)
29 0.000 0.000 0.000 0.000 schema.py:339(__eq__)
1 0.000 0.000 0.000 0.000 schema.py:353(ForeignKey)
17 0.000 0.000 0.000 0.000 schema.py:356(__init__)
4 0.000 0.000 0.000 0.000 schema.py:367(copy)
4 0.000 0.000 0.000 0.000 schema.py:371
(_get_colspec)
38 0.000 0.000 0.010 0.000 schema.py:379(references)
55 0.000 0.000 0.000 0.000 schema.py:383
(_init_column)
55 0.000 0.000 0.000 0.000 schema.py:407(<lambda>)
94 0.000 0.000 0.000 0.000 schema.py:409
(accept_visitor)
17 0.000 0.000 0.000 0.000 schema.py:413
(_set_parent)
1 0.000 0.000 0.000 0.000 schema.py:422
(DefaultGenerator)
11 0.000 0.000 0.000 0.000 schema.py:425
(_set_parent)
1 0.000 0.000 0.000 0.000 schema.py:431
(PassiveDefault)
1 0.000 0.000 0.000 0.000 schema.py:440
(ColumnDefault)
1 0.000 0.000 0.000 0.000 schema.py:451(Sequence)
11 0.000 0.000 0.000 0.000 schema.py:453(__init__)
92 0.000 0.000 0.000 0.000 schema.py:464
(accept_visitor)
1 0.000 0.000 0.000 0.000 schema.py:468(Index)
339 0.000 0.000 0.010 0.000 schema.py:49(__getattr__)
1 0.000 0.000 0.000 0.000 schema.py:515
(SchemaEngine)
1 0.000 0.000 0.000 0.000 schema.py:534
(SchemaVisitor)
227 0.000 0.000 0.000 0.000 schema.py:542
(visit_column)
94 0.000 0.000 0.000 0.000 schema.py:545
(visit_foreign_key)
92 0.000 0.000 0.000 0.000 schema.py:557
(visit_sequence)
25 0.000 0.000 0.000 0.000 schema.py:56
(_get_table_key)
1 0.000 0.000 0.000 0.000 schema.py:64
(TableSingleton)
25 0.010 0.000 0.070 0.003 schema.py:66(__call__)
1 0.000 0.000 0.000 0.000 schema.py:98(Table)
...
Again, this is only the profile results for schema.py. Notice that
the total CPU time roughly halved while number of function calls
roughly doubled. If you want I could send the entire profile, but
it's really huge.
~ Daniel
-------------------------------------------------------
This SF.Net email is sponsored by xPML, a groundbreaking scripting language
that extends applications into web and mobile media. Attend the live webcast
and join the prime developer group breaking into this new coding territory!
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
_______________________________________________
Sqlalchemy-users mailing list
Sqlalchemy-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/sqlalchemy-users
