[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