[ZODB-Dev] Understanding the ZODB cache-size option

Marius Gedminas marius at gedmin.as
Tue Mar 23 18:13:54 EDT 2010


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?
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 197 bytes
Desc: Digital signature
Url : http://mail.zope.org/pipermail/zodb-dev/attachments/20100324/280178ae/attachment.bin 


More information about the ZODB-Dev mailing list