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?

Attachment: 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

Reply via email to