Hi Michael, I've ported your modifications on my tests, but I still can't get the same results: runs 2X slower than with 0.2.8 and I can't figure out why (MySQL version ???)... Anyway, I've continued my investigation, and may have a proposal to make it way faster.
Back to my profiling results, I've compared the ncalls between 0.2.8 and 0.3.1. Thats ~700 000 vs. ~ 2 400 000 calls (~ 3X more), running the test. As you said, this is due the "two-or-three hop path from MapperProperty->eager loading code", and reducing this path doesn't improve speed that much. But profiling also shows a interresting thing: "isinstance" is called 10X more in 0.3 than 0.2.8. Looking at SA code, I've found that orm.attributes.AttributeManager.managed_attributes() is called a *lot* of time while saving objs. Clearly, this ncalls difference comes from here. This func, given a class, returns a list (yielded) a InstrumentedAttribute. The problem is it's called for each *object*, repeatidly searching those attributes: for attr in manager.managed_attributes(obj.__class__): # blabla If objects are of the same class, this dramatically decrease the speed. I can suggest to cache the results of this func. In orm.attributes.AttributeManager.managed_attributes(): class AttributeManager(object): def __init__(self): self.attr_cache = {} # blabla def managed_attributes(self, class_): # results in cache ? if self.attr_cache.has_key(class_): return self.attr_cache[class_] # nope. caching... self.attr_cache[class_] = [] if not isinstance(class_, type): raise repr(class_) + " is not a type" for key in dir(class_): value = getattr(class_, key, None) if isinstance(value, InstrumentedAttribute): self.attr_cache[class_].append(value) return self.attr_cache[class_] (yes, yield is not used anymore is this code...) This is memory vs. cpu optimisation, and I didn't track the used memory, but I bet it's not that much... And that's worth it! Here the results *without* this modifications (0.3.1 rev 2127 still ~ 2X slower for me): SA 0.2.8: 2006-12-06 12:13:44.932276: Loading sis 2006-12-06 12:13:45.614073: 377 sis loaded 2006-12-06 12:13:45.614562: Creating indicators 2006-12-06 12:13:45.735367: 127 indicators created 2006-12-06 12:13:45.736245: registering... 2006-12-06 12:13:46.966250: ok done ! total time 2.03361010551 real 0m2.595s user 0m1.860s sys 0m0.112s SA 0.3.1 rev 2127 2006-12-06 12:14:30.619091: Loading sis 2006-12-06 12:14:31.466031: 377 sis loaded 2006-12-06 12:14:31.466499: Creating indicators 2006-12-06 12:14:31.562919: 127 indicators created 2006-12-06 12:14:31.563745: registering... 2006-12-06 12:14:34.798755: ok done ! total time 4.17961120605 real 0m4.770s user 0m4.152s sys 0m0.092s Now with caching, this gives: SA 0.3.1 rev 2127 + attr caching: 2006-12-06 12:17:28.765317: Loading sis 2006-12-06 12:17:29.487502: 377 sis loaded 2006-12-06 12:17:29.487972: Creating indicators 2006-12-06 12:17:29.583032: 127 indicators created 2006-12-06 12:17:29.583848: registering... 2006-12-06 12:17:31.175295: ok done ! total time 2.40989303589 real 0m3.115s user 0m2.368s sys 0m0.100s What do you think about this suggestion ? Cheers, -- Sébastien LELONG [EMAIL PROTECTED] --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "sqlalchemy" group. To post to this group, send email to sqlalchemy@googlegroups.com 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 -~----------~----~----~----~------~----~------~--~---