On Tue, Mar 23, 2010 at 01:57:50PM -0400, Jim Fulton wrote: > Some notes: > > - The Python profiler (cProfile) can help analyze object loading, > especially if you have good profiler analysis tools. Unfortunately, > I'm not aware of one that's included with Python. My nutty > pstats2html script, > > http://svn.zope.org/Sandbox/J1m/pstats2html.py?view=auto > > which I wrote before I learned javascript :), can show you who's > calling Connection.setstate, and thus, who's doing lots of loads.
http://github.com/Ignas/nous.pystat has some very early but interesting code that hooks into Connection.setstate and records the traceback. You get back a load profile that shows how many objects (both directly and indirectly) were loaded from each function, plus a breakdown by object class, as well as total number of bytes (sum of pickle sizes). Ignore the "seconds" and .00 fractions in the output, the code is counting the number of objects, but reusing a print function from a real profiler that assumes time. Neither I nor Ignas had time to fix the output formatting. Example output: % cumulative self time seconds seconds name 0.00 2104.00 1950.00 __init__.py:653:makeTimetableCalendar("<class 'schooltool.timetable.model.PersistentTimetableCalendarEvent'>", 1950), ('size', 1894192) 0.00 43.00 43.00 adapter.py:74:_customizeUnprotected("<class 'schooltool.relationship.relationship.LinkSet'>", 23), ("<class 'schooltool.app.cal.Calendar'>", 20), ('size', 9845) 0.00 57.00 27.00 relationship.py:694:getTargetsByRole("<class 'schooltool.relationship.relationship.Link'>", 27), ('size', 19273) 0.00 23.00 23.00 relationship.py:637:getLinksByRole("<type 'BTrees.OOBTree.OOBTree'>", 23), ('size', 5899) 0.00 22.00 22.00 adapter.py:570:subscribers('size', 6082), ("<class 'schooltool.course.section.Section'>", 20), ("<class 'schooltool.group.group.Group'>", 2) 0.00 22.00 22.00 attribute.py:49:__getitem__("<type 'BTrees.OOBTree.OOBTree'>", 22), ('size', 6692) 0.00 21.00 21.00 cal.py:109:__iter__("<class 'persistent.mapping.PersistentMapping'>", 21), ('size', 255851) 0.00 7.00 7.00 UserList.py:28:__getitem__("<class 'persistent.list.PersistentList'>", 7), ('size', 1126) 0.00 4.00 4.00 adapter.py:517:queryMultiAdapter("<class 'schooltool.term.term.Term'>", 1), ("<class 'schooltool.course.section.SectionContainer'>", 1), ("<class 'schooltool.schoolyear.schoolyear.SchoolYear'>", 2), ('size', 2604) 0.00 2.00 2.00 __init__.py:71:getObject("<type 'BTrees.IOBTree.IOBucket'>", 1), ("<type 'BTrees.IOBTree.IOBTree'>", 1), ('size', 4940) 0.00 5.00 1.00 section.py:72:__str__("<class 'zope.intid.IntIds'>", 1), ('size', 258) 0.00 2.00 1.00 cal.py:551:update('size', 94), ("<class 'zope.session.session.SessionPkgData'>", 1) 0.00 2.00 1.00 schoolyear.py:344:activeSchoolYear("<class 'schooltool.schoolyear.schoolyear.SchoolYearContainer'>", 1), ('size', 336) 0.00 1.00 1.00 btree.py:86:__getitem__("<type 'BTrees.OOBTree.OOBTree'>", 1), ('size', 149) 0.00 1.00 1.00 UserDict.py:44:has_key("<type 'BTrees.OOBTree.OOBTree'>", 1), ('size', 86) 0.00 2126.00 0.00 httpserver.py:1046:<lambda> 0.00 2126.00 0.00 publish.py:117:publish 0.00 2126.00 0.00 SocketServer.py:252:finish_request 0.00 2126.00 0.00 httpserver.py:417:handle_one_request 0.00 2126.00 0.00 tales.py:691:evaluate 0.00 2126.00 0.00 httpserver.py:433:handle 0.00 2126.00 0.00 pagetemplate.py:102:pt_render 0.00 2126.00 0.00 threading.py:468:__bootstrap_inner 0.00 2126.00 0.00 threading.py:448:__bootstrap 0.00 2126.00 0.00 __init__.py:51:__call__ 0.00 2126.00 0.00 SocketServer.py:516:__init__ 0.00 2126.00 0.00 cal.py:936:__call__ 0.00 2126.00 0.00 publish.py:113:debug_call 0.00 2126.00 0.00 zodbprof.py:6:zodbprof 0.00 2126.00 0.00 httpserver.py:840:worker_thread_callback 0.00 2126.00 0.00 httpserver.py:1055:process_request_in_thread 0.00 2126.00 0.00 viewpagetemplatefile.py:43:__call__ 0.00 2126.00 0.00 talinterpreter.py:267:__call__ 0.00 2126.00 0.00 publish.py:61:mapply 0.00 2126.00 0.00 BaseHTTPServer.py:312:handle 0.00 2126.00 0.00 talinterpreter.py:328:interpret 0.00 2126.00 0.00 viewpagetemplatefile.py:78:__call__ 0.00 2126.00 0.00 httpserver.py:278:wsgi_execute 0.00 2126.00 0.00 threading.py:444:run 0.00 2126.00 0.00 <string>:1:__call__ 0.00 2126.00 0.00 zopepublication.py:203:callObject 0.00 2124.00 0.00 talinterpreter.py:527:do_optTag_tal 0.00 2124.00 0.00 talinterpreter.py:507:no_tag 0.00 2124.00 0.00 talinterpreter.py:862:do_useMacro 0.00 2124.00 0.00 talinterpreter.py:515:do_optTag 0.00 2121.00 0.00 talinterpreter.py:915:do_defineSlot 0.00 2109.00 0.00 talinterpreter.py:582:do_setLocal_tal 0.00 2108.00 0.00 simpleviewclass.py:43:__call__ 0.00 2108.00 0.00 skin.py:119:render 0.00 2108.00 0.00 tales.py:54:__call__ 0.00 2108.00 0.00 talinterpreter.py:741:do_insertStructure_tal 0.00 2105.00 0.00 cal.py:655:dayEvents 0.00 2105.00 0.00 <string>:1:<module> 0.00 2105.00 0.00 cal.py:705:getDays 0.00 2105.00 0.00 cal.py:720:_getDays 0.00 2105.00 0.00 cal.py:683:getEvents 0.00 2105.00 0.00 cal.py:895:getDays 0.00 2105.00 0.00 pythonexpr.py:56:__call__ 0.00 2104.00 0.00 cal.py:673:getCalendars 0.00 2104.00 0.00 overlay.py:199:getCalendars 0.00 114.00 0.00 __init__.py:647:collectTimetableSourceObjects 0.00 114.00 0.00 source.py:48:getTimetableSourceObjects 0.00 102.00 0.00 relationship.py:210:getRelatedObjects 0.00 65.00 0.00 hooks.py:104:adapter_hook 0.00 65.00 0.00 adapter.py:80:__call__ 0.00 22.00 0.00 registry.py:322:subscribers 0.00 22.00 0.00 _api.py:132:subscribers 0.00 22.00 0.00 annotatable.py:32:getRelationshipLinks 0.00 21.00 0.00 expressions.py:182:_eval 0.00 21.00 0.00 expressions.py:214:__call__ 0.00 17.00 0.00 talinterpreter.py:379:do_startTag 0.00 17.00 0.00 talinterpreter.py:468:attrAction_tal 0.00 17.00 0.00 talinterpreter.py:850:do_condition 0.00 17.00 0.00 tales.py:703:evaluateText 0.00 16.00 0.00 cal.py:381:linkAllowed 0.00 16.00 0.00 talinterpreter.py:818:do_loop_tal 0.00 10.00 0.00 policy.py:47:checkByAdaptation 0.00 10.00 0.00 crowds.py:225:contains 0.00 10.00 0.00 checker.py:88:canWrite 0.00 10.00 0.00 section.py:284:contains 0.00 10.00 0.00 policy.py:36:checkPermission 0.00 10.00 0.00 relationship.py:362:__iter__ 0.00 10.00 0.00 crowds.py:83:contains 0.00 6.00 0.00 absoluteurl.py:70:__call__ 0.00 6.00 0.00 absoluteurl.py:34:absoluteURL 0.00 6.00 0.00 absoluteurl.py:43:__str__ 0.00 6.00 0.00 cal.py:322:viewLink 0.00 4.00 0.00 registry.py:238:queryMultiAdapter 0.00 4.00 0.00 _api.py:114:queryMultiAdapter 0.00 3.00 0.00 _api.py:108:getMultiAdapter 0.00 1.00 0.00 engine.py:53:__call__ 0.00 1.00 0.00 expressions.py:108:_eval 0.00 1.00 0.00 adapters.py:96:traversePathElement 0.00 1.00 0.00 namespace.py:42:namespaceLookup 0.00 1.00 0.00 schoolyear.py:102:getActiveSchoolYear 0.00 1.00 0.00 mixins.py:102:expand 0.00 1.00 0.00 UserDict.py:57:get --- Sample count: 2126 Total time: 2126.000000 seconds 2207427 size 1950 <class 'schooltool.timetable.model.PersistentTimetableCalendarEvent'> 47 <type 'BTrees.OOBTree.OOBTree'> 27 <class 'schooltool.relationship.relationship.Link'> 23 <class 'schooltool.relationship.relationship.LinkSet'> 21 <class 'persistent.mapping.PersistentMapping'> 20 <class 'schooltool.app.cal.Calendar'> 20 <class 'schooltool.course.section.Section'> 7 <class 'persistent.list.PersistentList'> 2 <class 'schooltool.schoolyear.schoolyear.SchoolYear'> 2 <class 'schooltool.group.group.Group'> 1 <type 'BTrees.IOBTree.IOBucket'> 1 <class 'schooltool.term.term.Term'> 1 <class 'schooltool.schoolyear.schoolyear.SchoolYearContainer'> 1 <type 'BTrees.IOBTree.IOBTree'> 1 <class 'zope.session.session.SessionPkgData'> 1 <class 'schooltool.course.section.SectionContainer'> 1 <class 'zope.intid.IntIds'> Marius Gedminas -- Did you know that 7/5 people don't know how to use fractions?
signature.asc
Description: Digital signature
_______________________________________________ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
