[Python-Dev] iterzip()

Jeremy Hylton jeremy@zope.com
Mon, 29 Apr 2002 19:02:52 -0400


>>>>> "NS" == Neil Schemenauer <nas@python.ca> writes:

  >> How does this come into play in the benchmark in question?  It
  >> seems like we should have gotten a lot of quick collections, but
  >> it was still quite slow.

  NS> The GC cost is paid early and the objects get put in an older
  NS> generation.  Obviously that's a waste of time if they are
  NS> deallocated in the near future.  justpush deallocates as it goes
  NS> so the GC is never triggered.

The "0," tuples aren't deallocated until the end of the function, so
it seems good to get them out of the current generation.

  NS> I just tried measuring the time spent in the GC while loading
  NS> some nasty web pages in our system (stuff that looks at
  NS> thousands of objects).  I used the Pentium cycle counter since
  NS> clock(2) seems to have very low resolution.  Setting threshold0
  NS> to 7500 makes the GC take up twice the amount of time as with
  NS> the default settings (700).  That surprised me.  I thought it
  NS> wouldn't make much difference.  Maybe I screwed up. :-)

Here's some data from gprof to be puzzled by.  I ran Tim's test with
only run(storetups) enabled.  Here's the top of the output:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 60.19      0.62     0.62   112233     0.01     0.01  PyObject_Malloc
  6.80      0.69     0.07   622804     0.00     0.00  visit_move
  4.85      0.74     0.05   621301     0.00     0.00  visit_decref
  4.85      0.79     0.05      168     0.30     0.67  list_traverse
  3.88      0.83     0.04      145     0.28     0.41  move_roots
  2.91      0.86     0.03   567141     0.00     0.00  tupletraverse
  1.94      0.88     0.02   286727     0.00     0.00  gc_list_append
  1.94      0.90     0.02   102050     0.00     0.00  tupledealloc
  1.94      0.92     0.02      145     0.14     0.89  move_root_reachable
  0.97      0.93     0.01   286727     0.00     0.00  gc_list_remove
  0.97      0.94     0.01   113171     0.00     0.00  PyObject_Free
  0.97      0.95     0.01   100043     0.00     0.00  list_ass_item
  0.97      0.96     0.01    32702     0.00     0.00  PyDict_Next
  0.97      0.97     0.01      489     0.02     1.78  eval_frame
  0.97      0.98     0.01      280     0.04     0.04  instancemethod_dealloc
  0.97      0.99     0.01      145     0.07     0.82  subtract_refs
  0.97      1.00     0.01      145     0.07     0.07  update_refs
  0.97      1.01     0.01        7     1.43     1.43  posix_stat
  0.97      1.02     0.01        6     1.67     1.67  member_get
  0.97      1.03     0.01        1    10.00    10.00  PyInt_Fini

So the profile output suggests that it's spending 60% of its time in
pymalloc.  

Jeremy